[==========] 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:03.185717 14611 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.14.68.254:34599
I20260812 06:19:03.186936 14611 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:03.187613 14611 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:03.195343 14617 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:03.195430 14616 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:03.195604 14611 server_base.cc:1061] running on GCE node
W20260812 06:19:03.195683 14620 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:03.196281 14611 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:03.196393 14611 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:03.196440 14611 hybrid_clock.cc:648] HybridClock initialized: now 1786515543196437 us; error 0 us; skew 500 ppm
I20260812 06:19:03.199761 14611 webserver.cc:533] Webserver started at http://127.14.68.254:39451/ using document root <none> and password file <none>
I20260812 06:19:03.200407 14611 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:03.200477 14611 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:03.200740 14611 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:03.202625 14611 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543174037-14611-0/minicluster-data/master-0-root/instance:
uuid: "9665762ab95c4a50bce27a7851d38290"
format_stamp: "Formatted at 2026-08-12 06:19:03 on dist-test-slave-ncp9"
I20260812 06:19:03.206830 14611 fs_manager.cc:696] Time spent creating directory manager: real 0.004s	user 0.005s	sys 0.000s
I20260812 06:19:03.209247 14629 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:03.210423 14611 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.001s
I20260812 06:19:03.210593 14611 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543174037-14611-0/minicluster-data/master-0-root
uuid: "9665762ab95c4a50bce27a7851d38290"
format_stamp: "Formatted at 2026-08-12 06:19:03 on dist-test-slave-ncp9"
I20260812 06:19:03.210701 14611 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543174037-14611-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543174037-14611-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543174037-14611-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:03.225816 14611 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:03.226581 14611 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:03.226761 14611 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:03.235033 14611 rpc_server.cc:307] RPC server started. Bound to: 127.14.68.254:34599
I20260812 06:19:03.235029 14706 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.14.68.254:34599 every 8 connection(s)
I20260812 06:19:03.237525 14707 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:03.244148 14707 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 9665762ab95c4a50bce27a7851d38290: Bootstrap starting.
I20260812 06:19:03.247445 14707 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 9665762ab95c4a50bce27a7851d38290: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:03.248649 14707 log.cc:826] T 00000000000000000000000000000000 P 9665762ab95c4a50bce27a7851d38290: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:03.251031 14707 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 9665762ab95c4a50bce27a7851d38290: No bootstrap required, opened a new log
I20260812 06:19:03.254379 14707 raft_consensus.cc:359] T 00000000000000000000000000000000 P 9665762ab95c4a50bce27a7851d38290 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9665762ab95c4a50bce27a7851d38290" member_type: VOTER }
I20260812 06:19:03.254604 14707 raft_consensus.cc:385] T 00000000000000000000000000000000 P 9665762ab95c4a50bce27a7851d38290 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:03.254664 14707 raft_consensus.cc:740] T 00000000000000000000000000000000 P 9665762ab95c4a50bce27a7851d38290 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 9665762ab95c4a50bce27a7851d38290, State: Initialized, Role: FOLLOWER
I20260812 06:19:03.255410 14707 consensus_queue.cc:260] T 00000000000000000000000000000000 P 9665762ab95c4a50bce27a7851d38290 [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: "9665762ab95c4a50bce27a7851d38290" member_type: VOTER }
I20260812 06:19:03.255595 14707 raft_consensus.cc:399] T 00000000000000000000000000000000 P 9665762ab95c4a50bce27a7851d38290 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:03.255662 14707 raft_consensus.cc:493] T 00000000000000000000000000000000 P 9665762ab95c4a50bce27a7851d38290 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:03.255808 14707 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 9665762ab95c4a50bce27a7851d38290 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:03.256768 14707 raft_consensus.cc:515] T 00000000000000000000000000000000 P 9665762ab95c4a50bce27a7851d38290 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9665762ab95c4a50bce27a7851d38290" member_type: VOTER }
I20260812 06:19:03.257507 14707 leader_election.cc:304] T 00000000000000000000000000000000 P 9665762ab95c4a50bce27a7851d38290 [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: 9665762ab95c4a50bce27a7851d38290; no voters: 
I20260812 06:19:03.257915 14707 leader_election.cc:290] T 00000000000000000000000000000000 P 9665762ab95c4a50bce27a7851d38290 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:03.258061 14714 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 9665762ab95c4a50bce27a7851d38290 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:03.258329 14714 raft_consensus.cc:697] T 00000000000000000000000000000000 P 9665762ab95c4a50bce27a7851d38290 [term 1 LEADER]: Becoming Leader. State: Replica: 9665762ab95c4a50bce27a7851d38290, State: Running, Role: LEADER
I20260812 06:19:03.258894 14714 consensus_queue.cc:237] T 00000000000000000000000000000000 P 9665762ab95c4a50bce27a7851d38290 [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: "9665762ab95c4a50bce27a7851d38290" member_type: VOTER }
I20260812 06:19:03.259183 14707 sys_catalog.cc:565] T 00000000000000000000000000000000 P 9665762ab95c4a50bce27a7851d38290 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:03.262307 14611 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:03.262380 14715 sys_catalog.cc:455] T 00000000000000000000000000000000 P 9665762ab95c4a50bce27a7851d38290 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "9665762ab95c4a50bce27a7851d38290" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9665762ab95c4a50bce27a7851d38290" member_type: VOTER } }
I20260812 06:19:03.262540 14715 sys_catalog.cc:458] T 00000000000000000000000000000000 P 9665762ab95c4a50bce27a7851d38290 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:03.262624 14716 sys_catalog.cc:455] T 00000000000000000000000000000000 P 9665762ab95c4a50bce27a7851d38290 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 9665762ab95c4a50bce27a7851d38290. Latest consensus state: current_term: 1 leader_uuid: "9665762ab95c4a50bce27a7851d38290" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9665762ab95c4a50bce27a7851d38290" member_type: VOTER } }
I20260812 06:19:03.262692 14716 sys_catalog.cc:458] T 00000000000000000000000000000000 P 9665762ab95c4a50bce27a7851d38290 [sys.catalog]: This master's current role is: LEADER
W20260812 06:19:03.265028 14737 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 9665762ab95c4a50bce27a7851d38290: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:19:03.265177 14737 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:19:03.265295 14738 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:03.266341 14738 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:03.272719 14738 catalog_manager.cc:1383] Generated new cluster ID: 06df7c485e3c4f52b03163b62647b36c
I20260812 06:19:03.272819 14738 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:03.289887 14738 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:03.290838 14738 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:03.300073 14738 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 9665762ab95c4a50bce27a7851d38290: Generated new TSK 0
I20260812 06:19:03.300830 14738 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:03.329043 14611 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:03.332011 14745 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:03.332039 14749 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:03.332137 14611 server_base.cc:1061] running on GCE node
W20260812 06:19:03.332283 14744 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:03.332491 14611 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:03.332541 14611 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:03.332561 14611 hybrid_clock.cc:648] HybridClock initialized: now 1786515543332561 us; error 0 us; skew 500 ppm
I20260812 06:19:03.333551 14611 webserver.cc:533] Webserver started at http://127.14.68.193:39507/ using document root <none> and password file <none>
I20260812 06:19:03.333724 14611 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:03.333776 14611 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:03.333866 14611 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:03.334257 14611 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543174037-14611-0/minicluster-data/ts-0-root/instance:
uuid: "90d7ddce56ec48e48ef52f632f74934f"
format_stamp: "Formatted at 2026-08-12 06:19:03 on dist-test-slave-ncp9"
I20260812 06:19:03.335924 14611 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:03.336876 14756 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:03.337164 14611 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:03.337235 14611 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543174037-14611-0/minicluster-data/ts-0-root
uuid: "90d7ddce56ec48e48ef52f632f74934f"
format_stamp: "Formatted at 2026-08-12 06:19:03 on dist-test-slave-ncp9"
I20260812 06:19:03.337311 14611 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543174037-14611-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543174037-14611-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543174037-14611-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:03.346215 14611 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:03.346711 14611 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:03.347227 14611 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:03.348158 14611 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:03.348217 14611 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:03.348268 14611 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:03.348299 14611 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:03.354943 14611 rpc_server.cc:307] RPC server started. Bound to: 127.14.68.193:45165
I20260812 06:19:03.354971 14859 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.14.68.193:45165 every 8 connection(s)
I20260812 06:19:03.369109 14860 heartbeater.cc:344] Connected to a master server at 127.14.68.254:34599
I20260812 06:19:03.369386 14860 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:03.369892 14860 heartbeater.cc:507] Master 127.14.68.254:34599 requested a full tablet report, sending...
I20260812 06:19:03.371448 14659 ts_manager.cc:194] Registered new tserver with Master: 90d7ddce56ec48e48ef52f632f74934f (127.14.68.193:45165)
I20260812 06:19:03.372316 14611 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.016724211s
I20260812 06:19:03.372704 14659 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:54862
I20260812 06:19:03.382957 14659 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:54866:
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:03.398250 14803 tablet_service.cc:1511] Processing CreateTablet for tablet 3c829c65716044bf8feb362686194898 (DEFAULT_TABLE table=heavy-update-compaction-test [id=59ddf262b5944556bea8b31c5e78fea1]), partition=
I20260812 06:19:03.398841 14803 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 3c829c65716044bf8feb362686194898. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:03.402333 14878 tablet_bootstrap.cc:492] T 3c829c65716044bf8feb362686194898 P 90d7ddce56ec48e48ef52f632f74934f: Bootstrap starting.
I20260812 06:19:03.403471 14878 tablet_bootstrap.cc:654] T 3c829c65716044bf8feb362686194898 P 90d7ddce56ec48e48ef52f632f74934f: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:03.405016 14878 tablet_bootstrap.cc:492] T 3c829c65716044bf8feb362686194898 P 90d7ddce56ec48e48ef52f632f74934f: No bootstrap required, opened a new log
I20260812 06:19:03.405143 14878 ts_tablet_manager.cc:1403] T 3c829c65716044bf8feb362686194898 P 90d7ddce56ec48e48ef52f632f74934f: Time spent bootstrapping tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:19:03.405656 14878 raft_consensus.cc:359] T 3c829c65716044bf8feb362686194898 P 90d7ddce56ec48e48ef52f632f74934f [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "90d7ddce56ec48e48ef52f632f74934f" member_type: VOTER last_known_addr { host: "127.14.68.193" port: 45165 } }
I20260812 06:19:03.405762 14878 raft_consensus.cc:385] T 3c829c65716044bf8feb362686194898 P 90d7ddce56ec48e48ef52f632f74934f [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:03.405786 14878 raft_consensus.cc:740] T 3c829c65716044bf8feb362686194898 P 90d7ddce56ec48e48ef52f632f74934f [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 90d7ddce56ec48e48ef52f632f74934f, State: Initialized, Role: FOLLOWER
I20260812 06:19:03.405920 14878 consensus_queue.cc:260] T 3c829c65716044bf8feb362686194898 P 90d7ddce56ec48e48ef52f632f74934f [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: "90d7ddce56ec48e48ef52f632f74934f" member_type: VOTER last_known_addr { host: "127.14.68.193" port: 45165 } }
I20260812 06:19:03.406019 14878 raft_consensus.cc:399] T 3c829c65716044bf8feb362686194898 P 90d7ddce56ec48e48ef52f632f74934f [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:03.406065 14878 raft_consensus.cc:493] T 3c829c65716044bf8feb362686194898 P 90d7ddce56ec48e48ef52f632f74934f [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:03.406118 14878 raft_consensus.cc:3060] T 3c829c65716044bf8feb362686194898 P 90d7ddce56ec48e48ef52f632f74934f [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:03.407051 14878 raft_consensus.cc:515] T 3c829c65716044bf8feb362686194898 P 90d7ddce56ec48e48ef52f632f74934f [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "90d7ddce56ec48e48ef52f632f74934f" member_type: VOTER last_known_addr { host: "127.14.68.193" port: 45165 } }
I20260812 06:19:03.407200 14878 leader_election.cc:304] T 3c829c65716044bf8feb362686194898 P 90d7ddce56ec48e48ef52f632f74934f [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: 90d7ddce56ec48e48ef52f632f74934f; no voters: 
I20260812 06:19:03.407404 14878 leader_election.cc:290] T 3c829c65716044bf8feb362686194898 P 90d7ddce56ec48e48ef52f632f74934f [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:03.407527 14880 raft_consensus.cc:2804] T 3c829c65716044bf8feb362686194898 P 90d7ddce56ec48e48ef52f632f74934f [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:03.407757 14880 raft_consensus.cc:697] T 3c829c65716044bf8feb362686194898 P 90d7ddce56ec48e48ef52f632f74934f [term 1 LEADER]: Becoming Leader. State: Replica: 90d7ddce56ec48e48ef52f632f74934f, State: Running, Role: LEADER
I20260812 06:19:03.408010 14860 heartbeater.cc:499] Master 127.14.68.254:34599 was elected leader, sending a full tablet report...
I20260812 06:19:03.407766 14878 ts_tablet_manager.cc:1434] T 3c829c65716044bf8feb362686194898 P 90d7ddce56ec48e48ef52f632f74934f: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:19:03.408488 14880 consensus_queue.cc:237] T 3c829c65716044bf8feb362686194898 P 90d7ddce56ec48e48ef52f632f74934f [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: "90d7ddce56ec48e48ef52f632f74934f" member_type: VOTER last_known_addr { host: "127.14.68.193" port: 45165 } }
I20260812 06:19:03.411999 14659 catalog_manager.cc:5719] T 3c829c65716044bf8feb362686194898 P 90d7ddce56ec48e48ef52f632f74934f reported cstate change: term changed from 0 to 1, leader changed from <none> to 90d7ddce56ec48e48ef52f632f74934f (127.14.68.193). New cstate: current_term: 1 leader_uuid: "90d7ddce56ec48e48ef52f632f74934f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "90d7ddce56ec48e48ef52f632f74934f" member_type: VOTER last_known_addr { host: "127.14.68.193" port: 45165 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:03.477021 14611 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.057s	user 0.022s	sys 0.004s
I20260812 06:19:03.606148 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling FlushMRSOp(3c829c65716044bf8feb362686194898): perf score=15.086190
I20260812 06:19:03.767668 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: FlushMRSOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.161s	user 0.118s	sys 0.035s Metrics: {"bytes_written":12307490,"cfile_init":1,"compiler_manager_pool.queue_time_us":526,"delete_count":0,"dirs.queue_time_us":57,"dirs.run_cpu_time_us":217,"dirs.run_wall_time_us":839,"drs_written":1,"lbm_read_time_us":76,"lbm_reads_lt_1ms":4,"lbm_write_time_us":38714,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"spinlock_wait_cycles":1280,"thread_start_us":142,"threads_started":1,"update_count":1500}
I20260812 06:19:03.769186 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling LogGCOp(3c829c65716044bf8feb362686194898): free 8725963 bytes of WAL
I20260812 06:19:03.769586 14774 log_reader.cc:385] T 3c829c65716044bf8feb362686194898: removed 1 log segments from log reader
I20260812 06:19:03.769706 14774 log.cc:1079] T 3c829c65716044bf8feb362686194898 P 90d7ddce56ec48e48ef52f632f74934f: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/3c829c65716044bf8feb362686194898/wal-000000001 (ops 1-6)
I20260812 06:19:03.772047 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: LogGCOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:19:03.772517 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898): perf score=2.188937
I20260812 06:19:03.797979 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.025s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5328,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:03.798524 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898): perf score=2.188937
I20260812 06:19:03.812734 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.014s	user 0.007s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4939,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:03.813230 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling MajorDeltaCompactionOp(3c829c65716044bf8feb362686194898): perf score=1.000000
I20260812 06:19:03.972507 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: MajorDeltaCompactionOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.159s	user 0.108s	sys 0.051s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733843,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":570,"lbm_read_time_us":12441,"lbm_reads_lt_1ms":573,"lbm_write_time_us":28512,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"thread_start_us":302,"threads_started":5,"update_count":2500}
I20260812 06:19:03.973064 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling UndoDeltaBlockGCOp(3c829c65716044bf8feb362686194898): 12308959 bytes on disk
I20260812 06:19:03.973584 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: UndoDeltaBlockGCOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4}
I20260812 06:19:03.974018 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898): perf score=10.126437
I20260812 06:19:04.015386 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.041s	user 0.014s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16484,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:04.016048 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling MajorDeltaCompactionOp(3c829c65716044bf8feb362686194898): perf score=1.000000
I20260812 06:19:04.135944 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: MajorDeltaCompactionOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.120s	user 0.103s	sys 0.016s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16528781,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1240,"lbm_read_time_us":8887,"lbm_reads_lt_1ms":363,"lbm_write_time_us":19533,"lbm_writes_lt_1ms":343,"mutex_wait_us":53,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":9984,"update_count":1500}
I20260812 06:19:04.136580 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898): perf score=10.126437
I20260812 06:19:04.181756 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.045s	user 0.021s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18692,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:04.182564 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898): perf score=2.188937
I20260812 06:19:04.195071 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4553,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:04.195534 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling MajorDeltaCompactionOp(3c829c65716044bf8feb362686194898): perf score=1.000000
I20260812 06:19:04.312579 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: MajorDeltaCompactionOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.117s	user 0.097s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":358,"lbm_read_time_us":8711,"lbm_reads_lt_1ms":464,"lbm_write_time_us":21697,"lbm_writes_lt_1ms":443,"mutex_wait_us":70,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:04.313230 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898): perf score=10.126437
I20260812 06:19:04.373068 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.060s	user 0.040s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":21030,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:04.373741 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898): perf score=2.188937
I20260812 06:19:04.385262 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4434,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:04.385771 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling MajorDeltaCompactionOp(3c829c65716044bf8feb362686194898): perf score=1.000000
I20260812 06:19:04.538548 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: MajorDeltaCompactionOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.153s	user 0.097s	sys 0.054s 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":145,"lbm_read_time_us":11245,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24998,"lbm_writes_lt_1ms":443,"mutex_wait_us":26,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14848,"update_count":2000}
I20260812 06:19:04.539090 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898): perf score=10.126437
I20260812 06:19:04.588510 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.049s	user 0.020s	sys 0.021s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18978,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:04.589107 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898): perf score=2.188937
I20260812 06:19:04.599475 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3758,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:04.600016 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling MajorDeltaCompactionOp(3c829c65716044bf8feb362686194898): perf score=1.000000
I20260812 06:19:04.726414 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: MajorDeltaCompactionOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.126s	user 0.106s	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":701,"lbm_read_time_us":8528,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25996,"lbm_writes_lt_1ms":443,"mutex_wait_us":277,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:04.727030 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898): perf score=10.126437
I20260812 06:19:04.770610 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.043s	user 0.030s	sys 0.012s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":18855,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:04.771199 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898): perf score=2.188937
I20260812 06:19:04.786068 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.015s	user 0.009s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5811,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:04.786790 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling MajorDeltaCompactionOp(3c829c65716044bf8feb362686194898): perf score=1.000000
I20260812 06:19:04.909729 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: MajorDeltaCompactionOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.123s	user 0.093s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631315,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":155,"lbm_read_time_us":9775,"lbm_reads_lt_1ms":468,"lbm_write_time_us":24248,"lbm_writes_lt_1ms":443,"mutex_wait_us":55,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6912,"update_count":2000}
I20260812 06:19:04.910531 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898): perf score=11.118625
I20260812 06:19:04.957788 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.047s	user 0.023s	sys 0.023s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":19412,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:04.958395 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898): perf score=2.188937
I20260812 06:19:04.974606 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.016s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5243,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:04.975095 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling FlushMRSOp(3c829c65716044bf8feb362686194898): perf score=1.000000
I20260812 06:19:05.023284 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: FlushMRSOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.048s	user 0.030s	sys 0.005s Metrics: {"bytes_written":1193504,"cfile_init":1,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":249,"dirs.run_wall_time_us":1568,"drs_written":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2223,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:05.024124 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling UndoDeltaBlockGCOp(3c829c65716044bf8feb362686194898): 463 bytes on disk
I20260812 06:19:05.024540 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: UndoDeltaBlockGCOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:19:05.025050 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898): perf score=3.181125
I20260812 06:19:05.039091 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.014s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4090,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:05.039582 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling LogGCOp(3c829c65716044bf8feb362686194898): free 124710288 bytes of WAL
I20260812 06:19:05.039810 14774 log_reader.cc:385] T 3c829c65716044bf8feb362686194898: removed 12 log segments from log reader
I20260812 06:19:05.039855 14774 log.cc:1079] T 3c829c65716044bf8feb362686194898 P 90d7ddce56ec48e48ef52f632f74934f: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/3c829c65716044bf8feb362686194898/wal-000000002 (ops 7-11)
I20260812 06:19:05.039885 14774 log.cc:1079] T 3c829c65716044bf8feb362686194898 P 90d7ddce56ec48e48ef52f632f74934f: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/3c829c65716044bf8feb362686194898/wal-000000003 (ops 12-16)
I20260812 06:19:05.039918 14774 log.cc:1079] T 3c829c65716044bf8feb362686194898 P 90d7ddce56ec48e48ef52f632f74934f: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/3c829c65716044bf8feb362686194898/wal-000000004 (ops 17-21)
I20260812 06:19:05.039949 14774 log.cc:1079] T 3c829c65716044bf8feb362686194898 P 90d7ddce56ec48e48ef52f632f74934f: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/3c829c65716044bf8feb362686194898/wal-000000005 (ops 22-26)
I20260812 06:19:05.039980 14774 log.cc:1079] T 3c829c65716044bf8feb362686194898 P 90d7ddce56ec48e48ef52f632f74934f: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/3c829c65716044bf8feb362686194898/wal-000000006 (ops 27-31)
I20260812 06:19:05.040012 14774 log.cc:1079] T 3c829c65716044bf8feb362686194898 P 90d7ddce56ec48e48ef52f632f74934f: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/3c829c65716044bf8feb362686194898/wal-000000007 (ops 32-36)
I20260812 06:19:05.040040 14774 log.cc:1079] T 3c829c65716044bf8feb362686194898 P 90d7ddce56ec48e48ef52f632f74934f: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/3c829c65716044bf8feb362686194898/wal-000000008 (ops 37-41)
I20260812 06:19:05.040062 14774 log.cc:1079] T 3c829c65716044bf8feb362686194898 P 90d7ddce56ec48e48ef52f632f74934f: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/3c829c65716044bf8feb362686194898/wal-000000009 (ops 42-46)
I20260812 06:19:05.040078 14774 log.cc:1079] T 3c829c65716044bf8feb362686194898 P 90d7ddce56ec48e48ef52f632f74934f: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/3c829c65716044bf8feb362686194898/wal-000000010 (ops 47-51)
I20260812 06:19:05.040093 14774 log.cc:1079] T 3c829c65716044bf8feb362686194898 P 90d7ddce56ec48e48ef52f632f74934f: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/3c829c65716044bf8feb362686194898/wal-000000011 (ops 52-56)
I20260812 06:19:05.040114 14774 log.cc:1079] T 3c829c65716044bf8feb362686194898 P 90d7ddce56ec48e48ef52f632f74934f: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/3c829c65716044bf8feb362686194898/wal-000000012 (ops 57-61)
I20260812 06:19:05.040153 14774 log.cc:1079] T 3c829c65716044bf8feb362686194898 P 90d7ddce56ec48e48ef52f632f74934f: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/3c829c65716044bf8feb362686194898/wal-000000013 (ops 62-66)
I20260812 06:19:05.065707 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: LogGCOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.026s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:19:05.066257 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898): perf score=2.188937
I20260812 06:19:05.088186 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.022s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6204,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:05.088776 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898): perf score=2.188937
I20260812 06:19:05.100875 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.012s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3432,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:05.101600 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling MajorDeltaCompactionOp(3c829c65716044bf8feb362686194898): perf score=1.000000
I20260812 06:19:05.315587 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: MajorDeltaCompactionOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.213s	user 0.149s	sys 0.061s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32938885,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":6868,"lbm_read_time_us":17705,"lbm_reads_lt_1ms":775,"lbm_write_time_us":37169,"lbm_writes_lt_1ms":743,"mutex_wait_us":3481,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":3968,"thread_start_us":107,"threads_started":1,"update_count":3500}
I20260812 06:19:05.316134 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898): perf score=15.087375
I20260812 06:19:05.386467 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.070s	user 0.029s	sys 0.028s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":25707,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:19:05.387080 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898): perf score=6.157687
I20260812 06:19:05.409102 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.022s	user 0.020s	sys 0.000s Metrics: {"bytes_written":7794837,"delete_count":0,"lbm_write_time_us":7919,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:19:05.409736 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling MajorDeltaCompactionOp(3c829c65716044bf8feb362686194898): perf score=1.000000
I20260812 06:19:05.567997 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: MajorDeltaCompactionOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.158s	user 0.117s	sys 0.040s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28836137,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":962,"lbm_read_time_us":10721,"lbm_reads_lt_1ms":668,"lbm_write_time_us":33510,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":642,"mutex_wait_us":322,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":15104,"update_count":3000}
I20260812 06:19:05.568544 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898): perf score=14.095187
I20260812 06:19:05.623330 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.055s	user 0.028s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24248,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:05.623888 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898): perf score=2.188937
I20260812 06:19:05.635691 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4047,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:05.636318 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling MajorDeltaCompactionOp(3c829c65716044bf8feb362686194898): perf score=1.000000
I20260812 06:19:05.806222 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: MajorDeltaCompactionOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.170s	user 0.116s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":963,"lbm_read_time_us":11000,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32216,"lbm_writes_lt_1ms":543,"mutex_wait_us":324,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14464,"update_count":2500}
I20260812 06:19:05.806829 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898): perf score=14.095187
I20260812 06:19:05.851171 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.044s	user 0.029s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19436,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:05.851752 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling MajorDeltaCompactionOp(3c829c65716044bf8feb362686194898): perf score=1.000000
I20260812 06:19:05.998240 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: MajorDeltaCompactionOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.146s	user 0.114s	sys 0.032s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20631192,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":293,"lbm_read_time_us":10087,"lbm_reads_lt_1ms":467,"lbm_write_time_us":24603,"lbm_writes_lt_1ms":443,"mutex_wait_us":76,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:19:05.998775 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898): perf score=11.118625
I20260812 06:19:06.036069 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.037s	user 0.027s	sys 0.007s Metrics: {"bytes_written":12430567,"delete_count":0,"lbm_write_time_us":16284,"lbm_writes_lt_1ms":306,"reinsert_count":0,"update_count":1515}
I20260812 06:19:06.036595 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898): perf score=2.188937
I20260812 06:19:06.048380 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3979584,"delete_count":0,"lbm_write_time_us":4569,"lbm_writes_lt_1ms":100,"reinsert_count":0,"update_count":485}
I20260812 06:19:06.048842 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling MajorDeltaCompactionOp(3c829c65716044bf8feb362686194898): perf score=1.000000
I20260812 06:19:06.198413 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: MajorDeltaCompactionOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.149s	user 0.119s	sys 0.025s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631314,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":957,"lbm_read_time_us":10237,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27663,"lbm_writes_lt_1ms":443,"mutex_wait_us":1331,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":2000}
I20260812 06:19:06.199072 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898): perf score=10.126437
I20260812 06:19:06.230444 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.031s	user 0.013s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13504,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:06.230968 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898): perf score=2.188937
I20260812 06:19:06.242432 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4109,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:06.242967 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling MajorDeltaCompactionOp(3c829c65716044bf8feb362686194898): perf score=1.000000
I20260812 06:19:06.375140 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: MajorDeltaCompactionOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.132s	user 0.107s	sys 0.025s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":160,"lbm_read_time_us":9305,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24956,"lbm_writes_lt_1ms":443,"mutex_wait_us":38,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":59648,"update_count":2000}
I20260812 06:19:06.375800 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898): perf score=10.126437
I20260812 06:19:06.421368 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.045s	user 0.027s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17345,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:06.422137 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898): perf score=2.188937
I20260812 06:19:06.433331 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3977,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:06.434177 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling FlushMRSOp(3c829c65716044bf8feb362686194898): perf score=1.000000
I20260812 06:19:06.466686 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: FlushMRSOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.032s	user 0.028s	sys 0.003s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":55,"dirs.run_cpu_time_us":209,"dirs.run_wall_time_us":1621,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2194,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:06.467505 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling LogGCOp(3c829c65716044bf8feb362686194898): free 124257249 bytes of WAL
I20260812 06:19:06.467760 14774 log_reader.cc:385] T 3c829c65716044bf8feb362686194898: removed 12 log segments from log reader
I20260812 06:19:06.467808 14774 log.cc:1079] T 3c829c65716044bf8feb362686194898 P 90d7ddce56ec48e48ef52f632f74934f: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/3c829c65716044bf8feb362686194898/wal-000000014 (ops 67-71)
I20260812 06:19:06.467849 14774 log.cc:1079] T 3c829c65716044bf8feb362686194898 P 90d7ddce56ec48e48ef52f632f74934f: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/3c829c65716044bf8feb362686194898/wal-000000015 (ops 72-76)
I20260812 06:19:06.467882 14774 log.cc:1079] T 3c829c65716044bf8feb362686194898 P 90d7ddce56ec48e48ef52f632f74934f: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/3c829c65716044bf8feb362686194898/wal-000000016 (ops 77-81)
I20260812 06:19:06.467907 14774 log.cc:1079] T 3c829c65716044bf8feb362686194898 P 90d7ddce56ec48e48ef52f632f74934f: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/3c829c65716044bf8feb362686194898/wal-000000017 (ops 82-86)
I20260812 06:19:06.467935 14774 log.cc:1079] T 3c829c65716044bf8feb362686194898 P 90d7ddce56ec48e48ef52f632f74934f: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/3c829c65716044bf8feb362686194898/wal-000000018 (ops 87-91)
I20260812 06:19:06.467963 14774 log.cc:1079] T 3c829c65716044bf8feb362686194898 P 90d7ddce56ec48e48ef52f632f74934f: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/3c829c65716044bf8feb362686194898/wal-000000019 (ops 92-96)
I20260812 06:19:06.467988 14774 log.cc:1079] T 3c829c65716044bf8feb362686194898 P 90d7ddce56ec48e48ef52f632f74934f: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/3c829c65716044bf8feb362686194898/wal-000000020 (ops 97-101)
I20260812 06:19:06.468010 14774 log.cc:1079] T 3c829c65716044bf8feb362686194898 P 90d7ddce56ec48e48ef52f632f74934f: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/3c829c65716044bf8feb362686194898/wal-000000021 (ops 102-106)
I20260812 06:19:06.468035 14774 log.cc:1079] T 3c829c65716044bf8feb362686194898 P 90d7ddce56ec48e48ef52f632f74934f: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/3c829c65716044bf8feb362686194898/wal-000000022 (ops 107-110)
I20260812 06:19:06.468065 14774 log.cc:1079] T 3c829c65716044bf8feb362686194898 P 90d7ddce56ec48e48ef52f632f74934f: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/3c829c65716044bf8feb362686194898/wal-000000023 (ops 111-115)
I20260812 06:19:06.468089 14774 log.cc:1079] T 3c829c65716044bf8feb362686194898 P 90d7ddce56ec48e48ef52f632f74934f: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/3c829c65716044bf8feb362686194898/wal-000000024 (ops 116-120)
I20260812 06:19:06.468119 14774 log.cc:1079] T 3c829c65716044bf8feb362686194898 P 90d7ddce56ec48e48ef52f632f74934f: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/3c829c65716044bf8feb362686194898/wal-000000025 (ops 121-125)
I20260812 06:19:06.495723 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: LogGCOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.028s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:19:06.496212 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling UndoDeltaBlockGCOp(3c829c65716044bf8feb362686194898): 462 bytes on disk
I20260812 06:19:06.496744 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: UndoDeltaBlockGCOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4}
I20260812 06:19:06.497455 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898): perf score=4.173312
I20260812 06:19:06.513952 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.016s	user 0.007s	sys 0.008s Metrics: {"bytes_written":5456465,"delete_count":0,"lbm_write_time_us":6558,"lbm_writes_lt_1ms":136,"reinsert_count":0,"update_count":665}
I20260812 06:19:06.514467 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898): perf score=1.196750
I20260812 06:19:06.526544 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":2748830,"delete_count":0,"lbm_write_time_us":4340,"lbm_writes_lt_1ms":70,"reinsert_count":0,"update_count":335}
I20260812 06:19:06.527098 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling MajorDeltaCompactionOp(3c829c65716044bf8feb362686194898): perf score=1.000000
I20260812 06:19:06.695238 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: MajorDeltaCompactionOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.168s	user 0.133s	sys 0.033s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836345,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":635,"lbm_read_time_us":11698,"lbm_reads_lt_1ms":674,"lbm_write_time_us":32677,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":384,"thread_start_us":89,"threads_started":1,"update_count":3000}
I20260812 06:19:06.695785 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898): perf score=14.095187
I20260812 06:19:06.745127 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.049s	user 0.013s	sys 0.036s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":20500,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:06.745801 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898): perf score=2.188937
I20260812 06:19:06.760277 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5467,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:06.760917 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling MajorDeltaCompactionOp(3c829c65716044bf8feb362686194898): perf score=1.000000
I20260812 06:19:06.928479 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: MajorDeltaCompactionOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.167s	user 0.143s	sys 0.024s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733720,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":680,"lbm_read_time_us":9749,"lbm_reads_lt_1ms":564,"lbm_write_time_us":35282,"lbm_writes_lt_1ms":543,"mutex_wait_us":52,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":18432,"update_count":2500}
I20260812 06:19:06.929064 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898): perf score=14.095187
I20260812 06:19:06.975241 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.046s	user 0.023s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20153,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:06.975867 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling MajorDeltaCompactionOp(3c829c65716044bf8feb362686194898): perf score=1.000000
I20260812 06:19:07.135407 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: MajorDeltaCompactionOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.159s	user 0.109s	sys 0.039s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20631192,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":288,"lbm_read_time_us":11362,"lbm_reads_lt_1ms":463,"lbm_write_time_us":24881,"lbm_writes_lt_1ms":443,"mutex_wait_us":91,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7424,"update_count":2000}
I20260812 06:19:07.136050 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898): perf score=14.095187
I20260812 06:19:07.187723 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.052s	user 0.028s	sys 0.017s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21784,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:07.188548 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898): perf score=2.188937
I20260812 06:19:07.202224 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.013s	user 0.008s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4143,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:07.202943 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling MajorDeltaCompactionOp(3c829c65716044bf8feb362686194898): perf score=1.000000
I20260812 06:19:07.390344 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: MajorDeltaCompactionOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.187s	user 0.142s	sys 0.036s 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":274,"lbm_read_time_us":12510,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28805,"lbm_writes_lt_1ms":543,"mutex_wait_us":85,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2500}
I20260812 06:19:07.390873 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898): perf score=14.095187
I20260812 06:19:07.446476 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.055s	user 0.030s	sys 0.024s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":24075,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:07.447062 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898): perf score=2.188937
I20260812 06:19:07.463724 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.016s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6126,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:07.464393 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling MajorDeltaCompactionOp(3c829c65716044bf8feb362686194898): perf score=1.000000
I20260812 06:19:07.627795 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: MajorDeltaCompactionOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.163s	user 0.111s	sys 0.037s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733725,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":897,"lbm_read_time_us":10457,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30659,"lbm_writes_lt_1ms":543,"mutex_wait_us":376,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:07.628587 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898): perf score=14.095187
I20260812 06:19:07.677713 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.049s	user 0.027s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19053,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:07.678251 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898): perf score=2.188937
I20260812 06:19:07.690672 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4246,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:07.691192 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling MajorDeltaCompactionOp(3c829c65716044bf8feb362686194898): perf score=1.000000
I20260812 06:19:07.849526 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: MajorDeltaCompactionOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.158s	user 0.110s	sys 0.035s 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":205,"lbm_read_time_us":10995,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29233,"lbm_writes_lt_1ms":543,"mutex_wait_us":66,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8192,"update_count":2500}
I20260812 06:19:07.850375 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898): perf score=14.095187
I20260812 06:19:07.900661 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.050s	user 0.033s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19583,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:07.901324 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898): perf score=2.188937
I20260812 06:19:07.913343 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3937,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:07.914014 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling FlushMRSOp(3c829c65716044bf8feb362686194898): perf score=1.000000
I20260812 06:19:07.941372 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: FlushMRSOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.027s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1275445,"cfile_init":1,"dirs.queue_time_us":62,"dirs.run_cpu_time_us":203,"dirs.run_wall_time_us":1322,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1573,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:07.942215 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling LogGCOp(3c829c65716044bf8feb362686194898): free 124710557 bytes of WAL
I20260812 06:19:07.942476 14774 log_reader.cc:385] T 3c829c65716044bf8feb362686194898: removed 12 log segments from log reader
I20260812 06:19:07.942569 14774 log.cc:1079] T 3c829c65716044bf8feb362686194898 P 90d7ddce56ec48e48ef52f632f74934f: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/3c829c65716044bf8feb362686194898/wal-000000026 (ops 126-130)
I20260812 06:19:07.942600 14774 log.cc:1079] T 3c829c65716044bf8feb362686194898 P 90d7ddce56ec48e48ef52f632f74934f: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/3c829c65716044bf8feb362686194898/wal-000000027 (ops 131-135)
I20260812 06:19:07.942616 14774 log.cc:1079] T 3c829c65716044bf8feb362686194898 P 90d7ddce56ec48e48ef52f632f74934f: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/3c829c65716044bf8feb362686194898/wal-000000028 (ops 136-140)
I20260812 06:19:07.942643 14774 log.cc:1079] T 3c829c65716044bf8feb362686194898 P 90d7ddce56ec48e48ef52f632f74934f: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/3c829c65716044bf8feb362686194898/wal-000000029 (ops 141-145)
I20260812 06:19:07.942675 14774 log.cc:1079] T 3c829c65716044bf8feb362686194898 P 90d7ddce56ec48e48ef52f632f74934f: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/3c829c65716044bf8feb362686194898/wal-000000030 (ops 146-150)
I20260812 06:19:07.942700 14774 log.cc:1079] T 3c829c65716044bf8feb362686194898 P 90d7ddce56ec48e48ef52f632f74934f: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/3c829c65716044bf8feb362686194898/wal-000000031 (ops 151-155)
I20260812 06:19:07.942731 14774 log.cc:1079] T 3c829c65716044bf8feb362686194898 P 90d7ddce56ec48e48ef52f632f74934f: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/3c829c65716044bf8feb362686194898/wal-000000032 (ops 156-160)
I20260812 06:19:07.942763 14774 log.cc:1079] T 3c829c65716044bf8feb362686194898 P 90d7ddce56ec48e48ef52f632f74934f: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/3c829c65716044bf8feb362686194898/wal-000000033 (ops 161-165)
I20260812 06:19:07.942795 14774 log.cc:1079] T 3c829c65716044bf8feb362686194898 P 90d7ddce56ec48e48ef52f632f74934f: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/3c829c65716044bf8feb362686194898/wal-000000034 (ops 166-170)
I20260812 06:19:07.942827 14774 log.cc:1079] T 3c829c65716044bf8feb362686194898 P 90d7ddce56ec48e48ef52f632f74934f: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/3c829c65716044bf8feb362686194898/wal-000000035 (ops 171-175)
I20260812 06:19:07.942858 14774 log.cc:1079] T 3c829c65716044bf8feb362686194898 P 90d7ddce56ec48e48ef52f632f74934f: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/3c829c65716044bf8feb362686194898/wal-000000036 (ops 176-180)
I20260812 06:19:07.942889 14774 log.cc:1079] T 3c829c65716044bf8feb362686194898 P 90d7ddce56ec48e48ef52f632f74934f: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/3c829c65716044bf8feb362686194898/wal-000000037 (ops 181-185)
I20260812 06:19:07.966372 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: LogGCOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.024s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:19:07.966835 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling UndoDeltaBlockGCOp(3c829c65716044bf8feb362686194898): 481 bytes on disk
I20260812 06:19:07.967260 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: UndoDeltaBlockGCOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4}
I20260812 06:19:07.967808 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898): perf score=3.181125
I20260812 06:19:07.980396 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.012s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":4555,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:07.981066 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898): perf score=2.188937
I20260812 06:19:07.996075 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5423,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:07.996834 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling MajorDeltaCompactionOp(3c829c65716044bf8feb362686194898): perf score=1.000000
I20260812 06:19:08.243899 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: MajorDeltaCompactionOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.247s	user 0.171s	sys 0.070s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32938771,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":260,"lbm_read_time_us":15453,"lbm_reads_lt_1ms":774,"lbm_write_time_us":42557,"lbm_writes_lt_1ms":743,"mutex_wait_us":66,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":8448,"thread_start_us":82,"threads_started":1,"update_count":3500}
I20260812 06:19:08.244853 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898): perf score=14.095187
I20260812 06:19:08.306574 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.061s	user 0.039s	sys 0.019s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":24302,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2000}
I20260812 06:19:08.307143 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898): perf score=3.181125
I20260812 06:19:08.331238 14611 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.854s	user 1.729s	sys 0.092s
I20260812 06:19:08.332830 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.026s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":5411,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:08.333360 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898): perf score=2.188937
I20260812 06:19:08.347857 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: FlushDeltaMemStoresOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.014s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5635,"lbm_writes_lt_1ms":93,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":450}
I20260812 06:19:08.348519 14861 maintenance_manager.cc:419] P 90d7ddce56ec48e48ef52f632f74934f: Scheduling MajorDeltaCompactionOp(3c829c65716044bf8feb362686194898): perf score=1.000000
I20260812 06:19:08.413827 14611 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.082s	user 0.004s	sys 0.000s
I20260812 06:19:08.414708 14611 tablet_server.cc:179] TabletServer@127.14.68.193:0 shutting down...
I20260812 06:19:08.508369 14774 maintenance_manager.cc:643] P 90d7ddce56ec48e48ef52f632f74934f: MajorDeltaCompactionOp(3c829c65716044bf8feb362686194898) complete. Timing: real 0.160s	user 0.116s	sys 0.044s Metrics: {"cfile_cache_hit":212,"cfile_cache_hit_bytes":8619242,"cfile_cache_miss":421,"cfile_cache_miss_bytes":20217002,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":440,"lbm_read_time_us":9351,"lbm_reads_lt_1ms":453,"lbm_write_time_us":30388,"lbm_writes_lt_1ms":643,"mutex_wait_us":99,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":124288,"update_count":3000}
I20260812 06:19:08.509260 14611 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:08.509740 14611 tablet_replica.cc:333] T 3c829c65716044bf8feb362686194898 P 90d7ddce56ec48e48ef52f632f74934f: stopping tablet replica
I20260812 06:19:08.510008 14611 raft_consensus.cc:2243] T 3c829c65716044bf8feb362686194898 P 90d7ddce56ec48e48ef52f632f74934f [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:08.510257 14611 raft_consensus.cc:2272] T 3c829c65716044bf8feb362686194898 P 90d7ddce56ec48e48ef52f632f74934f [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:08.526332 14611 tablet_server.cc:196] TabletServer@127.14.68.193:0 shutdown complete.
I20260812 06:19:08.562456 14611 master.cc:562] Master@127.14.68.254:34599 shutting down...
I20260812 06:19:08.566143 14611 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 9665762ab95c4a50bce27a7851d38290 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:08.566351 14611 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 9665762ab95c4a50bce27a7851d38290 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:08.566432 14611 tablet_replica.cc:333] T 00000000000000000000000000000000 P 9665762ab95c4a50bce27a7851d38290: stopping tablet replica
I20260812 06:19:08.579012 14611 master.cc:584] Master@127.14.68.254:34599 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5828 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:09.026012 14611 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.14.68.254:40017
I20260812 06:19:09.026427 14611 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:09.029084 14910 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:09.029081 14909 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:09.029173 14917 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:09.029147 14611 server_base.cc:1061] running on GCE node
I20260812 06:19:09.029512 14611 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:09.029551 14611 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:09.029563 14611 hybrid_clock.cc:648] HybridClock initialized: now 1786515549029564 us; error 0 us; skew 500 ppm
I20260812 06:19:09.030395 14611 webserver.cc:533] Webserver started at http://127.14.68.254:33423/ using document root <none> and password file <none>
I20260812 06:19:09.030539 14611 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:09.030586 14611 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:09.030644 14611 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:09.031009 14611 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543174037-14611-0/minicluster-data/master-0-root/instance:
uuid: "acf89a96c50c4451aedffa163d70ab9e"
format_stamp: "Formatted at 2026-08-12 06:19:09 on dist-test-slave-ncp9"
I20260812 06:19:09.032773 14611 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:09.033860 14922 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:09.034122 14611 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:09.034198 14611 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543174037-14611-0/minicluster-data/master-0-root
uuid: "acf89a96c50c4451aedffa163d70ab9e"
format_stamp: "Formatted at 2026-08-12 06:19:09 on dist-test-slave-ncp9"
I20260812 06:19:09.034264 14611 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543174037-14611-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543174037-14611-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543174037-14611-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:09.044355 14611 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:09.044749 14611 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:09.048635 14611 rpc_server.cc:307] RPC server started. Bound to: 127.14.68.254:40017
I20260812 06:19:09.053067 15021 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.14.68.254:40017 every 8 connection(s)
I20260812 06:19:09.053642 15026 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:09.055670 15026 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P acf89a96c50c4451aedffa163d70ab9e: Bootstrap starting.
I20260812 06:19:09.056542 15026 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P acf89a96c50c4451aedffa163d70ab9e: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:09.057789 15026 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P acf89a96c50c4451aedffa163d70ab9e: No bootstrap required, opened a new log
I20260812 06:19:09.058212 15026 raft_consensus.cc:359] T 00000000000000000000000000000000 P acf89a96c50c4451aedffa163d70ab9e [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "acf89a96c50c4451aedffa163d70ab9e" member_type: VOTER }
I20260812 06:19:09.058305 15026 raft_consensus.cc:385] T 00000000000000000000000000000000 P acf89a96c50c4451aedffa163d70ab9e [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:09.058336 15026 raft_consensus.cc:740] T 00000000000000000000000000000000 P acf89a96c50c4451aedffa163d70ab9e [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: acf89a96c50c4451aedffa163d70ab9e, State: Initialized, Role: FOLLOWER
I20260812 06:19:09.058487 15026 consensus_queue.cc:260] T 00000000000000000000000000000000 P acf89a96c50c4451aedffa163d70ab9e [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: "acf89a96c50c4451aedffa163d70ab9e" member_type: VOTER }
I20260812 06:19:09.058588 15026 raft_consensus.cc:399] T 00000000000000000000000000000000 P acf89a96c50c4451aedffa163d70ab9e [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:09.058632 15026 raft_consensus.cc:493] T 00000000000000000000000000000000 P acf89a96c50c4451aedffa163d70ab9e [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:09.058681 15026 raft_consensus.cc:3060] T 00000000000000000000000000000000 P acf89a96c50c4451aedffa163d70ab9e [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:09.059398 15026 raft_consensus.cc:515] T 00000000000000000000000000000000 P acf89a96c50c4451aedffa163d70ab9e [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "acf89a96c50c4451aedffa163d70ab9e" member_type: VOTER }
I20260812 06:19:09.059537 15026 leader_election.cc:304] T 00000000000000000000000000000000 P acf89a96c50c4451aedffa163d70ab9e [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: acf89a96c50c4451aedffa163d70ab9e; no voters: 
I20260812 06:19:09.059752 15026 leader_election.cc:290] T 00000000000000000000000000000000 P acf89a96c50c4451aedffa163d70ab9e [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:09.059903 15029 raft_consensus.cc:2804] T 00000000000000000000000000000000 P acf89a96c50c4451aedffa163d70ab9e [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:09.060115 15029 raft_consensus.cc:697] T 00000000000000000000000000000000 P acf89a96c50c4451aedffa163d70ab9e [term 1 LEADER]: Becoming Leader. State: Replica: acf89a96c50c4451aedffa163d70ab9e, State: Running, Role: LEADER
I20260812 06:19:09.060218 15026 sys_catalog.cc:565] T 00000000000000000000000000000000 P acf89a96c50c4451aedffa163d70ab9e [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:09.060272 15029 consensus_queue.cc:237] T 00000000000000000000000000000000 P acf89a96c50c4451aedffa163d70ab9e [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: "acf89a96c50c4451aedffa163d70ab9e" member_type: VOTER }
I20260812 06:19:09.060701 15030 sys_catalog.cc:455] T 00000000000000000000000000000000 P acf89a96c50c4451aedffa163d70ab9e [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "acf89a96c50c4451aedffa163d70ab9e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "acf89a96c50c4451aedffa163d70ab9e" member_type: VOTER } }
I20260812 06:19:09.060812 15030 sys_catalog.cc:458] T 00000000000000000000000000000000 P acf89a96c50c4451aedffa163d70ab9e [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:09.060716 15031 sys_catalog.cc:455] T 00000000000000000000000000000000 P acf89a96c50c4451aedffa163d70ab9e [sys.catalog]: SysCatalogTable state changed. Reason: New leader acf89a96c50c4451aedffa163d70ab9e. Latest consensus state: current_term: 1 leader_uuid: "acf89a96c50c4451aedffa163d70ab9e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "acf89a96c50c4451aedffa163d70ab9e" member_type: VOTER } }
I20260812 06:19:09.060863 15031 sys_catalog.cc:458] T 00000000000000000000000000000000 P acf89a96c50c4451aedffa163d70ab9e [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:09.061110 15037 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:09.061992 15037 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:09.062148 14611 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:09.063771 15037 catalog_manager.cc:1383] Generated new cluster ID: 2759a0c82f6a4dc98a8de3961d77ad67
I20260812 06:19:09.063827 15037 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:09.076517 15037 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:09.077250 15037 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:09.082005 15037 catalog_manager.cc:6092] T 00000000000000000000000000000000 P acf89a96c50c4451aedffa163d70ab9e: Generated new TSK 0
I20260812 06:19:09.082252 15037 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:09.094777 14611 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:09.097263 15061 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:09.097276 15063 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:09.097373 15060 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:09.097386 14611 server_base.cc:1061] running on GCE node
I20260812 06:19:09.097808 14611 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:09.097857 14611 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:09.097879 14611 hybrid_clock.cc:648] HybridClock initialized: now 1786515549097878 us; error 0 us; skew 500 ppm
I20260812 06:19:09.098887 14611 webserver.cc:533] Webserver started at http://127.14.68.193:41281/ using document root <none> and password file <none>
I20260812 06:19:09.099071 14611 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:09.099126 14611 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:09.099215 14611 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:09.099628 14611 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543174037-14611-0/minicluster-data/ts-0-root/instance:
uuid: "17669640f49249e296446eeccdade8ee"
format_stamp: "Formatted at 2026-08-12 06:19:09 on dist-test-slave-ncp9"
I20260812 06:19:09.101482 14611 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:19:09.103186 15075 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:09.103744 14611 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:19:09.103965 14611 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543174037-14611-0/minicluster-data/ts-0-root
uuid: "17669640f49249e296446eeccdade8ee"
format_stamp: "Formatted at 2026-08-12 06:19:09 on dist-test-slave-ncp9"
I20260812 06:19:09.104104 14611 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543174037-14611-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543174037-14611-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543174037-14611-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:09.113885 14611 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:09.114768 14611 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:09.115190 14611 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:09.115724 14611 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:09.115767 14611 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:09.115813 14611 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:09.115840 14611 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:09.120535 14611 rpc_server.cc:307] RPC server started. Bound to: 127.14.68.193:43315
I20260812 06:19:09.120569 15177 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.14.68.193:43315 every 8 connection(s)
I20260812 06:19:09.131878 15178 heartbeater.cc:344] Connected to a master server at 127.14.68.254:40017
I20260812 06:19:09.132119 15178 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:09.132520 15178 heartbeater.cc:507] Master 127.14.68.254:40017 requested a full tablet report, sending...
I20260812 06:19:09.133672 14956 ts_manager.cc:194] Registered new tserver with Master: 17669640f49249e296446eeccdade8ee (127.14.68.193:43315)
I20260812 06:19:09.134606 14956 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:58910
I20260812 06:19:09.134716 14611 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.013753395s
I20260812 06:19:09.145221 14956 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:58924:
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:09.156342 15121 tablet_service.cc:1511] Processing CreateTablet for tablet f08c185e4ee249be9665f0f1ef1c9715 (DEFAULT_TABLE table=heavy-update-compaction-test [id=44f81bbeb27440cc80a9ef9ae4bcdcff]), partition=
I20260812 06:19:09.156646 15121 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet f08c185e4ee249be9665f0f1ef1c9715. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:09.159235 15197 tablet_bootstrap.cc:492] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee: Bootstrap starting.
I20260812 06:19:09.160477 15197 tablet_bootstrap.cc:654] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:09.163055 15197 tablet_bootstrap.cc:492] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee: No bootstrap required, opened a new log
I20260812 06:19:09.163183 15197 ts_tablet_manager.cc:1403] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee: Time spent bootstrapping tablet: real 0.004s	user 0.003s	sys 0.000s
I20260812 06:19:09.163676 15197 raft_consensus.cc:359] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "17669640f49249e296446eeccdade8ee" member_type: VOTER last_known_addr { host: "127.14.68.193" port: 43315 } }
I20260812 06:19:09.163781 15197 raft_consensus.cc:385] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:09.163805 15197 raft_consensus.cc:740] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 17669640f49249e296446eeccdade8ee, State: Initialized, Role: FOLLOWER
I20260812 06:19:09.163932 15197 consensus_queue.cc:260] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee [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: "17669640f49249e296446eeccdade8ee" member_type: VOTER last_known_addr { host: "127.14.68.193" port: 43315 } }
I20260812 06:19:09.164049 15197 raft_consensus.cc:399] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:09.164076 15197 raft_consensus.cc:493] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:09.164105 15197 raft_consensus.cc:3060] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:09.165249 15197 raft_consensus.cc:515] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "17669640f49249e296446eeccdade8ee" member_type: VOTER last_known_addr { host: "127.14.68.193" port: 43315 } }
I20260812 06:19:09.165405 15197 leader_election.cc:304] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee [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: 17669640f49249e296446eeccdade8ee; no voters: 
I20260812 06:19:09.165638 15197 leader_election.cc:290] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:09.165807 15199 raft_consensus.cc:2804] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:09.165987 15197 ts_tablet_manager.cc:1434] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee: Time spent starting tablet: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:19:09.166004 15178 heartbeater.cc:499] Master 127.14.68.254:40017 was elected leader, sending a full tablet report...
I20260812 06:19:09.166090 15199 raft_consensus.cc:697] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee [term 1 LEADER]: Becoming Leader. State: Replica: 17669640f49249e296446eeccdade8ee, State: Running, Role: LEADER
I20260812 06:19:09.166265 15199 consensus_queue.cc:237] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee [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: "17669640f49249e296446eeccdade8ee" member_type: VOTER last_known_addr { host: "127.14.68.193" port: 43315 } }
I20260812 06:19:09.167774 14956 catalog_manager.cc:5719] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee reported cstate change: term changed from 0 to 1, leader changed from <none> to 17669640f49249e296446eeccdade8ee (127.14.68.193). New cstate: current_term: 1 leader_uuid: "17669640f49249e296446eeccdade8ee" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "17669640f49249e296446eeccdade8ee" member_type: VOTER last_known_addr { host: "127.14.68.193" port: 43315 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:09.230681 14611 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.056s	user 0.021s	sys 0.004s
I20260812 06:19:09.372438 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling FlushMRSOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=19.054940
I20260812 06:19:09.522547 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: FlushMRSOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.150s	user 0.116s	sys 0.032s Metrics: {"bytes_written":8902492,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":69,"dirs.run_cpu_time_us":274,"dirs.run_wall_time_us":978,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":34681,"lbm_writes_lt_1ms":674,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1085}
I20260812 06:19:09.523655 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling LogGCOp(f08c185e4ee249be9665f0f1ef1c9715): free 20743880 bytes of WAL
I20260812 06:19:09.524029 15085 log_reader.cc:385] T f08c185e4ee249be9665f0f1ef1c9715: removed 2 log segments from log reader
I20260812 06:19:09.524137 15085 log.cc:1079] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/f08c185e4ee249be9665f0f1ef1c9715/wal-000000001 (ops 1-6)
I20260812 06:19:09.524210 15085 log.cc:1079] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/f08c185e4ee249be9665f0f1ef1c9715/wal-000000002 (ops 7-11)
I20260812 06:19:09.528934 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: LogGCOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.005s	user 0.002s	sys 0.003s Metrics: {}
I20260812 06:19:09.529395 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling UndoDeltaBlockGCOp(f08c185e4ee249be9665f0f1ef1c9715): 16411396 bytes on disk
I20260812 06:19:09.529884 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: UndoDeltaBlockGCOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":79,"lbm_reads_lt_1ms":4}
I20260812 06:19:09.530318 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=2.188937
I20260812 06:19:09.549410 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.019s	user 0.013s	sys 0.004s Metrics: {"bytes_written":3405230,"delete_count":0,"lbm_write_time_us":4293,"lbm_writes_lt_1ms":86,"reinsert_count":0,"update_count":415}
I20260812 06:19:09.550117 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling MajorDeltaCompactionOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=1.000000
I20260812 06:19:09.689383 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: MajorDeltaCompactionOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.139s	user 0.087s	sys 0.051s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16569850,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":88,"lbm_read_time_us":9236,"lbm_reads_lt_1ms":360,"lbm_write_time_us":22674,"lbm_writes_lt_1ms":343,"peak_mem_usage":38262756,"reinsert_count":0,"thread_start_us":320,"threads_started":5,"update_count":1500}
I20260812 06:19:09.689997 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=10.126437
I20260812 06:19:09.728020 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.038s	user 0.021s	sys 0.013s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16103,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:09.728631 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=2.188937
I20260812 06:19:09.740789 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4208,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:09.741441 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling MajorDeltaCompactionOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=1.000000
I20260812 06:19:09.876461 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: MajorDeltaCompactionOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.135s	user 0.114s	sys 0.019s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":176,"lbm_read_time_us":9769,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24622,"lbm_writes_lt_1ms":443,"mutex_wait_us":85,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12800,"update_count":2000}
I20260812 06:19:09.877107 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=10.126437
I20260812 06:19:09.919651 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.042s	user 0.025s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15419,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:09.920264 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=2.188937
I20260812 06:19:09.936154 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.016s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5977,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:09.936698 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling MajorDeltaCompactionOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=1.000000
I20260812 06:19:10.061802 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: MajorDeltaCompactionOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.125s	user 0.105s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":212,"lbm_read_time_us":10981,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20925,"lbm_writes_lt_1ms":443,"mutex_wait_us":44,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6272,"update_count":2000}
I20260812 06:19:10.062389 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=10.126437
I20260812 06:19:10.117825 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.055s	user 0.022s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15557,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:10.118666 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=2.188937
I20260812 06:19:10.132508 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5462,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:10.133131 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling MajorDeltaCompactionOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=1.000000
I20260812 06:19:10.294081 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: MajorDeltaCompactionOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.161s	user 0.096s	sys 0.064s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":976,"lbm_read_time_us":12935,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25917,"lbm_writes_lt_1ms":443,"mutex_wait_us":35,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":97408,"update_count":2000}
I20260812 06:19:10.294607 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=10.126437
I20260812 06:19:10.340296 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.046s	user 0.024s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15047,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:10.340970 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=2.188937
I20260812 06:19:10.351949 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4014,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:10.352638 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling MajorDeltaCompactionOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=1.000000
I20260812 06:19:10.480018 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: MajorDeltaCompactionOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.127s	user 0.115s	sys 0.012s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":978,"lbm_read_time_us":8996,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24604,"lbm_writes_lt_1ms":443,"mutex_wait_us":280,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14720,"update_count":2000}
I20260812 06:19:10.480594 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=10.126437
I20260812 06:19:10.517690 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.037s	user 0.021s	sys 0.012s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":14636,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:10.518249 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=2.188937
I20260812 06:19:10.528740 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3941,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:10.529438 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling MajorDeltaCompactionOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=1.000000
I20260812 06:19:10.658779 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: MajorDeltaCompactionOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.129s	user 0.110s	sys 0.019s 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":319,"lbm_read_time_us":11287,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24149,"lbm_writes_lt_1ms":443,"mutex_wait_us":38,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":23552,"update_count":2000}
I20260812 06:19:10.659497 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=10.126437
I20260812 06:19:10.704914 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.045s	user 0.020s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13844,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:10.705554 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=2.188937
I20260812 06:19:10.721206 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.015s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5933,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:10.721777 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling MajorDeltaCompactionOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=1.000000
I20260812 06:19:10.875851 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: MajorDeltaCompactionOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.154s	user 0.114s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":246,"lbm_read_time_us":10650,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26369,"lbm_writes_lt_1ms":443,"mutex_wait_us":35,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6912,"update_count":2000}
I20260812 06:19:10.876554 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=10.126437
I20260812 06:19:10.923166 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.046s	user 0.023s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18070,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:10.923688 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=2.188937
I20260812 06:19:10.934547 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3916,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:10.935352 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling FlushMRSOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=1.000000
I20260812 06:19:10.965121 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: FlushMRSOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.030s	user 0.026s	sys 0.004s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":54,"dirs.run_cpu_time_us":199,"dirs.run_wall_time_us":1419,"drs_written":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1743,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:10.965827 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling LogGCOp(f08c185e4ee249be9665f0f1ef1c9715): free 124710246 bytes of WAL
I20260812 06:19:10.966087 15085 log_reader.cc:385] T f08c185e4ee249be9665f0f1ef1c9715: removed 12 log segments from log reader
I20260812 06:19:10.966136 15085 log.cc:1079] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/f08c185e4ee249be9665f0f1ef1c9715/wal-000000003 (ops 12-16)
I20260812 06:19:10.966214 15085 log.cc:1079] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/f08c185e4ee249be9665f0f1ef1c9715/wal-000000004 (ops 17-21)
I20260812 06:19:10.966255 15085 log.cc:1079] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/f08c185e4ee249be9665f0f1ef1c9715/wal-000000005 (ops 22-26)
I20260812 06:19:10.966289 15085 log.cc:1079] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/f08c185e4ee249be9665f0f1ef1c9715/wal-000000006 (ops 27-31)
I20260812 06:19:10.966320 15085 log.cc:1079] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/f08c185e4ee249be9665f0f1ef1c9715/wal-000000007 (ops 32-36)
I20260812 06:19:10.966348 15085 log.cc:1079] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/f08c185e4ee249be9665f0f1ef1c9715/wal-000000008 (ops 37-41)
I20260812 06:19:10.966377 15085 log.cc:1079] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/f08c185e4ee249be9665f0f1ef1c9715/wal-000000009 (ops 42-46)
I20260812 06:19:10.966408 15085 log.cc:1079] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/f08c185e4ee249be9665f0f1ef1c9715/wal-000000010 (ops 47-51)
I20260812 06:19:10.966436 15085 log.cc:1079] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/f08c185e4ee249be9665f0f1ef1c9715/wal-000000011 (ops 52-56)
I20260812 06:19:10.966466 15085 log.cc:1079] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/f08c185e4ee249be9665f0f1ef1c9715/wal-000000012 (ops 57-61)
I20260812 06:19:10.966496 15085 log.cc:1079] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/f08c185e4ee249be9665f0f1ef1c9715/wal-000000013 (ops 62-66)
I20260812 06:19:10.966526 15085 log.cc:1079] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/f08c185e4ee249be9665f0f1ef1c9715/wal-000000014 (ops 67-71)
I20260812 06:19:10.993678 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: LogGCOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.028s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:19:10.994295 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling UndoDeltaBlockGCOp(f08c185e4ee249be9665f0f1ef1c9715): 482 bytes on disk
I20260812 06:19:10.994887 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: UndoDeltaBlockGCOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":80,"lbm_reads_lt_1ms":4}
I20260812 06:19:10.995399 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=4.173312
I20260812 06:19:11.022015 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.026s	user 0.014s	sys 0.011s Metrics: {"bytes_written":5661585,"delete_count":0,"lbm_write_time_us":7052,"lbm_writes_lt_1ms":141,"reinsert_count":0,"update_count":690}
I20260812 06:19:11.022605 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=1.196750
I20260812 06:19:11.030598 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.008s	user 0.001s	sys 0.005s Metrics: {"bytes_written":2543704,"delete_count":0,"lbm_write_time_us":2550,"lbm_writes_lt_1ms":65,"reinsert_count":0,"update_count":310}
I20260812 06:19:11.031088 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling MajorDeltaCompactionOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=1.000000
I20260812 06:19:11.240375 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: MajorDeltaCompactionOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.209s	user 0.127s	sys 0.082s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877303,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":191,"lbm_read_time_us":14548,"lbm_reads_lt_1ms":674,"lbm_write_time_us":35494,"lbm_writes_lt_1ms":643,"mutex_wait_us":71,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":16768,"thread_start_us":78,"threads_started":1,"update_count":3000}
I20260812 06:19:11.240970 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=14.095187
I20260812 06:19:11.307473 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.066s	user 0.030s	sys 0.029s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":22629,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:11.308025 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=2.188937
I20260812 06:19:11.318672 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3950,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:11.319218 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling MajorDeltaCompactionOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=1.000000
I20260812 06:19:11.513324 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: MajorDeltaCompactionOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.194s	user 0.126s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":228,"lbm_read_time_us":13446,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32281,"lbm_writes_lt_1ms":543,"mutex_wait_us":37,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3968,"update_count":2500}
I20260812 06:19:11.513877 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=14.095187
I20260812 06:19:11.561779 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.048s	user 0.024s	sys 0.020s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19474,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:11.562312 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=2.188937
I20260812 06:19:11.582942 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.020s	user 0.007s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3991,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:11.583544 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling MajorDeltaCompactionOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=1.000000
I20260812 06:19:11.774926 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: MajorDeltaCompactionOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.191s	user 0.117s	sys 0.064s 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":1143,"lbm_read_time_us":14620,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28360,"lbm_writes_lt_1ms":543,"mutex_wait_us":360,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6400,"update_count":2500}
I20260812 06:19:11.775449 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=14.095187
I20260812 06:19:11.826828 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.051s	user 0.030s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22154,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:11.827491 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=2.188937
I20260812 06:19:11.843263 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.016s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6196,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:11.843797 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling MajorDeltaCompactionOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=1.000000
I20260812 06:19:12.029140 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: MajorDeltaCompactionOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.185s	user 0.132s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":751,"lbm_read_time_us":11577,"lbm_reads_lt_1ms":564,"lbm_write_time_us":28880,"lbm_writes_lt_1ms":543,"mutex_wait_us":37,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8704,"update_count":2500}
I20260812 06:19:12.029781 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=14.095187
I20260812 06:19:12.079192 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.049s	user 0.018s	sys 0.028s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23604,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:12.079761 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=2.188937
I20260812 06:19:12.100032 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.020s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6136,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:12.100633 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling MajorDeltaCompactionOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=1.000000
I20260812 06:19:12.276687 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: MajorDeltaCompactionOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.176s	user 0.133s	sys 0.032s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":628,"lbm_read_time_us":10139,"lbm_reads_lt_1ms":564,"lbm_write_time_us":32458,"lbm_writes_lt_1ms":543,"mutex_wait_us":65,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2500}
I20260812 06:19:12.277380 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=14.095187
I20260812 06:19:12.326442 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.049s	user 0.020s	sys 0.027s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":22766,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:12.327097 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=2.188937
I20260812 06:19:12.343883 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.017s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6190,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:12.344442 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling MajorDeltaCompactionOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=1.000000
I20260812 06:19:12.510296 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: MajorDeltaCompactionOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.166s	user 0.113s	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":673,"lbm_read_time_us":12390,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30325,"lbm_writes_lt_1ms":543,"mutex_wait_us":60,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9088,"update_count":2500}
I20260812 06:19:12.510955 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=14.095187
I20260812 06:19:12.567641 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.056s	user 0.041s	sys 0.007s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22467,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:12.568205 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=2.188937
I20260812 06:19:12.579970 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4070,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:12.580469 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling FlushMRSOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=1.000000
I20260812 06:19:12.610927 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: FlushMRSOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.030s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":195,"dirs.run_wall_time_us":1646,"drs_written":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1613,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:19:12.611627 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling LogGCOp(f08c185e4ee249be9665f0f1ef1c9715): free 133024452 bytes of WAL
I20260812 06:19:12.611862 15085 log_reader.cc:385] T f08c185e4ee249be9665f0f1ef1c9715: removed 13 log segments from log reader
I20260812 06:19:12.611907 15085 log.cc:1079] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/f08c185e4ee249be9665f0f1ef1c9715/wal-000000015 (ops 72-76)
I20260812 06:19:12.611935 15085 log.cc:1079] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/f08c185e4ee249be9665f0f1ef1c9715/wal-000000016 (ops 77-81)
I20260812 06:19:12.611965 15085 log.cc:1079] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/f08c185e4ee249be9665f0f1ef1c9715/wal-000000017 (ops 82-86)
I20260812 06:19:12.611996 15085 log.cc:1079] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/f08c185e4ee249be9665f0f1ef1c9715/wal-000000018 (ops 87-91)
I20260812 06:19:12.612028 15085 log.cc:1079] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/f08c185e4ee249be9665f0f1ef1c9715/wal-000000019 (ops 92-96)
I20260812 06:19:12.612058 15085 log.cc:1079] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/f08c185e4ee249be9665f0f1ef1c9715/wal-000000020 (ops 97-100)
I20260812 06:19:12.612089 15085 log.cc:1079] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/f08c185e4ee249be9665f0f1ef1c9715/wal-000000021 (ops 101-105)
I20260812 06:19:12.612118 15085 log.cc:1079] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/f08c185e4ee249be9665f0f1ef1c9715/wal-000000022 (ops 106-110)
I20260812 06:19:12.612155 15085 log.cc:1079] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/f08c185e4ee249be9665f0f1ef1c9715/wal-000000023 (ops 111-115)
I20260812 06:19:12.612178 15085 log.cc:1079] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/f08c185e4ee249be9665f0f1ef1c9715/wal-000000024 (ops 116-120)
I20260812 06:19:12.612210 15085 log.cc:1079] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/f08c185e4ee249be9665f0f1ef1c9715/wal-000000025 (ops 121-125)
I20260812 06:19:12.612241 15085 log.cc:1079] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/f08c185e4ee249be9665f0f1ef1c9715/wal-000000026 (ops 126-130)
I20260812 06:19:12.612272 15085 log.cc:1079] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/f08c185e4ee249be9665f0f1ef1c9715/wal-000000027 (ops 131-135)
I20260812 06:19:12.642660 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: LogGCOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.031s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:19:12.643262 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=5.165500
I20260812 06:19:12.663014 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.020s	user 0.009s	sys 0.008s Metrics: {"bytes_written":6728209,"delete_count":0,"lbm_write_time_us":7920,"lbm_writes_lt_1ms":167,"reinsert_count":0,"update_count":820}
I20260812 06:19:12.663691 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling UndoDeltaBlockGCOp(f08c185e4ee249be9665f0f1ef1c9715): 493 bytes on disk
I20260812 06:19:12.664395 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: UndoDeltaBlockGCOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":92,"lbm_reads_lt_1ms":4}
I20260812 06:19:12.665125 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=1.000000
I20260812 06:19:12.679472 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.014s	user 0.005s	sys 0.000s Metrics: {"bytes_written":1477052,"delete_count":0,"lbm_write_time_us":2104,"lbm_writes_lt_1ms":39,"reinsert_count":0,"update_count":180}
I20260812 06:19:12.680053 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling MajorDeltaCompactionOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=1.000000
I20260812 06:19:12.886931 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: MajorDeltaCompactionOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.207s	user 0.147s	sys 0.048s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979689,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1599,"lbm_read_time_us":13801,"lbm_reads_lt_1ms":766,"lbm_write_time_us":40054,"lbm_writes_lt_1ms":743,"mutex_wait_us":368,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":5760,"thread_start_us":112,"threads_started":1,"update_count":3500}
I20260812 06:19:12.887624 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=18.063937
I20260812 06:19:12.949129 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.061s	user 0.045s	sys 0.016s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":27117,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:12.949817 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=2.188937
I20260812 06:19:12.965788 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.016s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5278,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:12.966355 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling MajorDeltaCompactionOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=1.000000
I20260812 06:19:13.145172 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: MajorDeltaCompactionOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.179s	user 0.128s	sys 0.050s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":527,"lbm_read_time_us":12376,"lbm_reads_lt_1ms":668,"lbm_write_time_us":36488,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":3000}
I20260812 06:19:13.147048 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=14.095187
I20260812 06:19:13.206468 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.059s	user 0.018s	sys 0.040s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24016,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:13.207054 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=2.188937
I20260812 06:19:13.237193 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.030s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5545,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:13.237686 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=2.188937
I20260812 06:19:13.248752 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3949,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:13.249286 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling MajorDeltaCompactionOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=1.000000
I20260812 06:19:13.418305 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: MajorDeltaCompactionOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.169s	user 0.133s	sys 0.036s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877220,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":742,"lbm_read_time_us":13807,"lbm_reads_lt_1ms":673,"lbm_write_time_us":33867,"lbm_writes_lt_1ms":643,"mutex_wait_us":61,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4096,"update_count":3000}
I20260812 06:19:13.419232 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=14.095187
I20260812 06:19:13.472199 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.053s	user 0.021s	sys 0.021s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":19795,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:13.472843 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=2.188937
I20260812 06:19:13.485592 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4407,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:13.486364 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling MajorDeltaCompactionOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=1.000000
I20260812 06:19:13.653635 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: MajorDeltaCompactionOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.167s	user 0.131s	sys 0.031s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1182,"lbm_read_time_us":12387,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31565,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":542,"mutex_wait_us":363,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8448,"update_count":2500}
I20260812 06:19:13.654258 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=12.110812
I20260812 06:19:13.691280 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.037s	user 0.014s	sys 0.020s Metrics: {"bytes_written":13866409,"delete_count":0,"lbm_write_time_us":15821,"lbm_writes_lt_1ms":341,"reinsert_count":0,"update_count":1690}
I20260812 06:19:13.691924 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=1.196750
I20260812 06:19:13.713865 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.022s	user 0.005s	sys 0.005s Metrics: {"bytes_written":2953959,"delete_count":0,"lbm_write_time_us":3813,"lbm_writes_lt_1ms":75,"reinsert_count":0,"update_count":360}
I20260812 06:19:13.714483 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=2.188937
I20260812 06:19:13.725126 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.010s	user 0.009s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3561,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:13.725684 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling MajorDeltaCompactionOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=1.000000
I20260812 06:19:13.923509 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: MajorDeltaCompactionOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.198s	user 0.124s	sys 0.064s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774773,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1091,"lbm_read_time_us":14640,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31519,"lbm_writes_lt_1ms":543,"mutex_wait_us":385,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4224,"update_count":2500}
I20260812 06:19:13.924188 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=14.095187
I20260812 06:19:13.984678 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.060s	user 0.028s	sys 0.019s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":22635,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:13.985311 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=2.188937
I20260812 06:19:13.995997 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.011s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3970,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:13.996515 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling FlushMRSOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=1.000000
I20260812 06:19:14.028357 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: FlushMRSOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.032s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1193507,"cfile_init":1,"dirs.queue_time_us":92,"dirs.run_cpu_time_us":252,"dirs.run_wall_time_us":1525,"drs_written":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2222,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:14.029086 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling LogGCOp(f08c185e4ee249be9665f0f1ef1c9715): free 120553650 bytes of WAL
I20260812 06:19:14.029299 15085 log_reader.cc:385] T f08c185e4ee249be9665f0f1ef1c9715: removed 12 log segments from log reader
I20260812 06:19:14.029340 15085 log.cc:1079] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/f08c185e4ee249be9665f0f1ef1c9715/wal-000000028 (ops 136-140)
I20260812 06:19:14.029368 15085 log.cc:1079] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/f08c185e4ee249be9665f0f1ef1c9715/wal-000000029 (ops 141-145)
I20260812 06:19:14.029398 15085 log.cc:1079] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/f08c185e4ee249be9665f0f1ef1c9715/wal-000000030 (ops 146-150)
I20260812 06:19:14.029431 15085 log.cc:1079] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/f08c185e4ee249be9665f0f1ef1c9715/wal-000000031 (ops 151-155)
I20260812 06:19:14.029466 15085 log.cc:1079] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/f08c185e4ee249be9665f0f1ef1c9715/wal-000000032 (ops 156-160)
I20260812 06:19:14.029498 15085 log.cc:1079] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/f08c185e4ee249be9665f0f1ef1c9715/wal-000000033 (ops 161-165)
I20260812 06:19:14.029529 15085 log.cc:1079] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/f08c185e4ee249be9665f0f1ef1c9715/wal-000000034 (ops 166-170)
I20260812 06:19:14.029559 15085 log.cc:1079] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/f08c185e4ee249be9665f0f1ef1c9715/wal-000000035 (ops 171-174)
I20260812 06:19:14.029597 15085 log.cc:1079] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/f08c185e4ee249be9665f0f1ef1c9715/wal-000000036 (ops 175-179)
I20260812 06:19:14.029627 15085 log.cc:1079] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/f08c185e4ee249be9665f0f1ef1c9715/wal-000000037 (ops 180-184)
I20260812 06:19:14.029657 15085 log.cc:1079] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/f08c185e4ee249be9665f0f1ef1c9715/wal-000000038 (ops 185-188)
I20260812 06:19:14.029690 15085 log.cc:1079] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee: Deleting log segment in path: /tmp/dist-test-taskwzcaPb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515543174037-14611-0/minicluster-data/ts-0-root/wals/f08c185e4ee249be9665f0f1ef1c9715/wal-000000039 (ops 189-193)
I20260812 06:19:14.053048 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: LogGCOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.024s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:19:14.053512 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling UndoDeltaBlockGCOp(f08c185e4ee249be9665f0f1ef1c9715): 462 bytes on disk
I20260812 06:19:14.054030 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: UndoDeltaBlockGCOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4}
I20260812 06:19:14.054675 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=2.188937
I20260812 06:19:14.082288 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.027s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5091,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:14.085321 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=2.188937
I20260812 06:19:14.099308 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: FlushDeltaMemStoresOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.014s	user 0.008s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5189,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:14.103247 15180 maintenance_manager.cc:419] P 17669640f49249e296446eeccdade8ee: Scheduling MajorDeltaCompactionOp(f08c185e4ee249be9665f0f1ef1c9715): perf score=1.000000
I20260812 06:19:14.184568 14611 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.954s	user 1.784s	sys 0.152s
I20260812 06:19:14.277944 14611 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.093s	user 0.002s	sys 0.000s
I20260812 06:19:14.278466 14611 tablet_server.cc:179] TabletServer@127.14.68.193:0 shutting down...
I20260812 06:19:14.317504 15085 maintenance_manager.cc:643] P 17669640f49249e296446eeccdade8ee: MajorDeltaCompactionOp(f08c185e4ee249be9665f0f1ef1c9715) complete. Timing: real 0.214s	user 0.142s	sys 0.071s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979748,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":746,"lbm_read_time_us":17492,"lbm_reads_lt_1ms":770,"lbm_write_time_us":31876,"lbm_writes_lt_1ms":743,"mutex_wait_us":129,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":30848,"thread_start_us":89,"threads_started":1,"update_count":3500}
I20260812 06:19:14.318815 14611 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:14.319113 14611 tablet_replica.cc:333] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee: stopping tablet replica
I20260812 06:19:14.319252 14611 raft_consensus.cc:2243] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:14.319433 14611 raft_consensus.cc:2272] T f08c185e4ee249be9665f0f1ef1c9715 P 17669640f49249e296446eeccdade8ee [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:14.335023 14611 tablet_server.cc:196] TabletServer@127.14.68.193:0 shutdown complete.
I20260812 06:19:14.375751 14611 master.cc:562] Master@127.14.68.254:40017 shutting down...
I20260812 06:19:14.379127 14611 raft_consensus.cc:2243] T 00000000000000000000000000000000 P acf89a96c50c4451aedffa163d70ab9e [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:14.379302 14611 raft_consensus.cc:2272] T 00000000000000000000000000000000 P acf89a96c50c4451aedffa163d70ab9e [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:14.379351 14611 tablet_replica.cc:333] T 00000000000000000000000000000000 P acf89a96c50c4451aedffa163d70ab9e: stopping tablet replica
I20260812 06:19:14.391795 14611 master.cc:584] Master@127.14.68.254:40017 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5457 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11286 ms total)

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