[==========] 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:17:24.669509 17588 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.17.45.62:36735
I20260812 06:17:24.670594 17588 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:17:24.671217 17588 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:17:24.678131 17588 server_base.cc:1061] running on GCE node
W20260812 06:17:24.678267 17597 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:17:24.678288 17598 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:17:24.678580 17601 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:17:24.679188 17588 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:24.679283 17588 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:17:24.679318 17588 hybrid_clock.cc:648] HybridClock initialized: now 1786515444679316 us; error 0 us; skew 500 ppm
I20260812 06:17:24.681258 17588 webserver.cc:533] Webserver started at http://127.17.45.62:37385/ using document root <none> and password file <none>
I20260812 06:17:24.681797 17588 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:24.681856 17588 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:24.682109 17588 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:24.683755 17588 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444658860-17588-0/minicluster-data/master-0-root/instance:
uuid: "a53ff167692243558b672d063ae0af85"
format_stamp: "Formatted at 2026-08-12 06:17:24 on dist-test-slave-mjjr"
I20260812 06:17:24.687206 17588 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.002s	sys 0.001s
I20260812 06:17:24.689347 17607 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:17:24.690353 17588 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.000s	sys 0.001s
I20260812 06:17:24.690451 17588 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444658860-17588-0/minicluster-data/master-0-root
uuid: "a53ff167692243558b672d063ae0af85"
format_stamp: "Formatted at 2026-08-12 06:17:24 on dist-test-slave-mjjr"
I20260812 06:17:24.690529 17588 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444658860-17588-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444658860-17588-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444658860-17588-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:17:24.705509 17588 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:24.706045 17588 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:17:24.706172 17588 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:24.714432 17588 rpc_server.cc:307] RPC server started. Bound to: 127.17.45.62:36735
I20260812 06:17:24.714450 17686 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.17.45.62:36735 every 8 connection(s)
I20260812 06:17:24.716807 17688 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:17:24.722106 17688 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P a53ff167692243558b672d063ae0af85: Bootstrap starting.
I20260812 06:17:24.724514 17688 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P a53ff167692243558b672d063ae0af85: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:24.725380 17688 log.cc:826] T 00000000000000000000000000000000 P a53ff167692243558b672d063ae0af85: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:24.727111 17688 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P a53ff167692243558b672d063ae0af85: No bootstrap required, opened a new log
I20260812 06:17:24.729903 17688 raft_consensus.cc:359] T 00000000000000000000000000000000 P a53ff167692243558b672d063ae0af85 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a53ff167692243558b672d063ae0af85" member_type: VOTER }
I20260812 06:17:24.730093 17688 raft_consensus.cc:385] T 00000000000000000000000000000000 P a53ff167692243558b672d063ae0af85 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:24.730186 17688 raft_consensus.cc:740] T 00000000000000000000000000000000 P a53ff167692243558b672d063ae0af85 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: a53ff167692243558b672d063ae0af85, State: Initialized, Role: FOLLOWER
I20260812 06:17:24.730755 17688 consensus_queue.cc:260] T 00000000000000000000000000000000 P a53ff167692243558b672d063ae0af85 [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: "a53ff167692243558b672d063ae0af85" member_type: VOTER }
I20260812 06:17:24.730949 17688 raft_consensus.cc:399] T 00000000000000000000000000000000 P a53ff167692243558b672d063ae0af85 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:24.731029 17688 raft_consensus.cc:493] T 00000000000000000000000000000000 P a53ff167692243558b672d063ae0af85 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:24.731171 17688 raft_consensus.cc:3060] T 00000000000000000000000000000000 P a53ff167692243558b672d063ae0af85 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:24.732036 17688 raft_consensus.cc:515] T 00000000000000000000000000000000 P a53ff167692243558b672d063ae0af85 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a53ff167692243558b672d063ae0af85" member_type: VOTER }
I20260812 06:17:24.732476 17688 leader_election.cc:304] T 00000000000000000000000000000000 P a53ff167692243558b672d063ae0af85 [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: a53ff167692243558b672d063ae0af85; no voters: 
I20260812 06:17:24.732803 17688 leader_election.cc:290] T 00000000000000000000000000000000 P a53ff167692243558b672d063ae0af85 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:24.732990 17691 raft_consensus.cc:2804] T 00000000000000000000000000000000 P a53ff167692243558b672d063ae0af85 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:24.733225 17691 raft_consensus.cc:697] T 00000000000000000000000000000000 P a53ff167692243558b672d063ae0af85 [term 1 LEADER]: Becoming Leader. State: Replica: a53ff167692243558b672d063ae0af85, State: Running, Role: LEADER
I20260812 06:17:24.733668 17691 consensus_queue.cc:237] T 00000000000000000000000000000000 P a53ff167692243558b672d063ae0af85 [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: "a53ff167692243558b672d063ae0af85" member_type: VOTER }
I20260812 06:17:24.733760 17688 sys_catalog.cc:565] T 00000000000000000000000000000000 P a53ff167692243558b672d063ae0af85 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:24.735703 17697 sys_catalog.cc:455] T 00000000000000000000000000000000 P a53ff167692243558b672d063ae0af85 [sys.catalog]: SysCatalogTable state changed. Reason: New leader a53ff167692243558b672d063ae0af85. Latest consensus state: current_term: 1 leader_uuid: "a53ff167692243558b672d063ae0af85" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a53ff167692243558b672d063ae0af85" member_type: VOTER } }
I20260812 06:17:24.735687 17692 sys_catalog.cc:455] T 00000000000000000000000000000000 P a53ff167692243558b672d063ae0af85 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "a53ff167692243558b672d063ae0af85" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a53ff167692243558b672d063ae0af85" member_type: VOTER } }
I20260812 06:17:24.735821 17697 sys_catalog.cc:458] T 00000000000000000000000000000000 P a53ff167692243558b672d063ae0af85 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:24.735821 17692 sys_catalog.cc:458] T 00000000000000000000000000000000 P a53ff167692243558b672d063ae0af85 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:24.736217 17588 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:17:24.738245 17721 catalog_manager.cc:1594] T 00000000000000000000000000000000 P a53ff167692243558b672d063ae0af85: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:17:24.738340 17721 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:17:24.738416 17720 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:24.739152 17720 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:24.744151 17720 catalog_manager.cc:1383] Generated new cluster ID: 0dd20428e1c14f779845948a436c8602
I20260812 06:17:24.744220 17720 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:24.757798 17720 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:24.758621 17720 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:24.768886 17720 catalog_manager.cc:6092] T 00000000000000000000000000000000 P a53ff167692243558b672d063ae0af85: Generated new TSK 0
I20260812 06:17:24.769600 17720 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:24.801254 17588 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:24.804430 17730 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:17:24.804481 17728 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:17:24.804699 17588 server_base.cc:1061] running on GCE node
W20260812 06:17:24.804742 17735 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:17:24.805073 17588 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:24.805136 17588 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:17:24.805159 17588 hybrid_clock.cc:648] HybridClock initialized: now 1786515444805159 us; error 0 us; skew 500 ppm
I20260812 06:17:24.806162 17588 webserver.cc:533] Webserver started at http://127.17.45.1:36309/ using document root <none> and password file <none>
I20260812 06:17:24.806334 17588 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:24.806401 17588 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:24.806478 17588 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:24.806941 17588 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444658860-17588-0/minicluster-data/ts-0-root/instance:
uuid: "341598efd47a40c8922f41c064400f38"
format_stamp: "Formatted at 2026-08-12 06:17:24 on dist-test-slave-mjjr"
I20260812 06:17:24.808856 17588 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:17:24.809981 17741 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:17:24.810282 17588 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:17:24.810360 17588 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444658860-17588-0/minicluster-data/ts-0-root
uuid: "341598efd47a40c8922f41c064400f38"
format_stamp: "Formatted at 2026-08-12 06:17:24 on dist-test-slave-mjjr"
I20260812 06:17:24.810417 17588 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444658860-17588-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444658860-17588-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444658860-17588-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:17:24.838570 17588 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:24.839123 17588 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:24.839707 17588 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:24.840643 17588 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:24.840699 17588 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:24.840770 17588 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:24.840811 17588 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:24.847879 17849 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.17.45.1:41197 every 8 connection(s)
I20260812 06:17:24.847904 17588 rpc_server.cc:307] RPC server started. Bound to: 127.17.45.1:41197
I20260812 06:17:24.857542 17851 heartbeater.cc:344] Connected to a master server at 127.17.45.62:36735
I20260812 06:17:24.857810 17851 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:24.858248 17851 heartbeater.cc:507] Master 127.17.45.62:36735 requested a full tablet report, sending...
I20260812 06:17:24.859835 17635 ts_manager.cc:194] Registered new tserver with Master: 341598efd47a40c8922f41c064400f38 (127.17.45.1:41197)
I20260812 06:17:24.859894 17588 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011327052s
I20260812 06:17:24.861374 17635 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:43534
I20260812 06:17:24.869557 17635 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:43550:
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:17:24.883088 17785 tablet_service.cc:1511] Processing CreateTablet for tablet ba73322e522340169bcd4241876b2e1e (DEFAULT_TABLE table=heavy-update-compaction-test [id=c4b0ed7e05094b46bbd00a00a932ba29]), partition=
I20260812 06:17:24.883617 17785 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet ba73322e522340169bcd4241876b2e1e. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:24.886631 17867 tablet_bootstrap.cc:492] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38: Bootstrap starting.
I20260812 06:17:24.888230 17867 tablet_bootstrap.cc:654] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:24.889411 17867 tablet_bootstrap.cc:492] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38: No bootstrap required, opened a new log
I20260812 06:17:24.889531 17867 ts_tablet_manager.cc:1403] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:17:24.890007 17867 raft_consensus.cc:359] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "341598efd47a40c8922f41c064400f38" member_type: VOTER last_known_addr { host: "127.17.45.1" port: 41197 } }
I20260812 06:17:24.890128 17867 raft_consensus.cc:385] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:24.890177 17867 raft_consensus.cc:740] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 341598efd47a40c8922f41c064400f38, State: Initialized, Role: FOLLOWER
I20260812 06:17:24.890331 17867 consensus_queue.cc:260] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38 [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: "341598efd47a40c8922f41c064400f38" member_type: VOTER last_known_addr { host: "127.17.45.1" port: 41197 } }
I20260812 06:17:24.890448 17867 raft_consensus.cc:399] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:24.890496 17867 raft_consensus.cc:493] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:24.890552 17867 raft_consensus.cc:3060] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:24.891546 17867 raft_consensus.cc:515] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "341598efd47a40c8922f41c064400f38" member_type: VOTER last_known_addr { host: "127.17.45.1" port: 41197 } }
I20260812 06:17:24.891724 17867 leader_election.cc:304] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38 [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: 341598efd47a40c8922f41c064400f38; no voters: 
I20260812 06:17:24.891975 17867 leader_election.cc:290] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:24.892068 17870 raft_consensus.cc:2804] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:24.892267 17870 raft_consensus.cc:697] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38 [term 1 LEADER]: Becoming Leader. State: Replica: 341598efd47a40c8922f41c064400f38, State: Running, Role: LEADER
I20260812 06:17:24.892352 17867 ts_tablet_manager.cc:1434] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:17:24.892472 17870 consensus_queue.cc:237] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38 [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: "341598efd47a40c8922f41c064400f38" member_type: VOTER last_known_addr { host: "127.17.45.1" port: 41197 } }
I20260812 06:17:24.892712 17851 heartbeater.cc:499] Master 127.17.45.62:36735 was elected leader, sending a full tablet report...
I20260812 06:17:24.895252 17635 catalog_manager.cc:5719] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38 reported cstate change: term changed from 0 to 1, leader changed from <none> to 341598efd47a40c8922f41c064400f38 (127.17.45.1). New cstate: current_term: 1 leader_uuid: "341598efd47a40c8922f41c064400f38" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "341598efd47a40c8922f41c064400f38" member_type: VOTER last_known_addr { host: "127.17.45.1" port: 41197 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:24.959332 17588 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.055s	user 0.020s	sys 0.004s
I20260812 06:17:25.099018 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling FlushMRSOp(ba73322e522340169bcd4241876b2e1e): perf score=19.054940
I20260812 06:17:25.285621 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: FlushMRSOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.186s	user 0.154s	sys 0.019s Metrics: {"bytes_written":12307490,"cfile_init":1,"compiler_manager_pool.queue_time_us":310,"delete_count":0,"dirs.queue_time_us":78,"dirs.run_cpu_time_us":241,"dirs.run_wall_time_us":927,"drs_written":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4,"lbm_write_time_us":43567,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":197,"threads_started":1,"update_count":1500}
I20260812 06:17:25.286865 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling LogGCOp(ba73322e522340169bcd4241876b2e1e): free 20743831 bytes of WAL
I20260812 06:17:25.287215 17747 log_reader.cc:385] T ba73322e522340169bcd4241876b2e1e: removed 2 log segments from log reader
I20260812 06:17:25.287300 17747 log.cc:1079] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/ba73322e522340169bcd4241876b2e1e/wal-000000001 (ops 1-6)
I20260812 06:17:25.287401 17747 log.cc:1079] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/ba73322e522340169bcd4241876b2e1e/wal-000000002 (ops 7-11)
I20260812 06:17:25.291579 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: LogGCOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.004s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:17:25.292080 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e): perf score=2.188937
I20260812 06:17:25.311969 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.020s	user 0.016s	sys 0.000s Metrics: {"bytes_written":4102660,"delete_count":0,"lbm_write_time_us":6517,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:25.312474 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling UndoDeltaBlockGCOp(ba73322e522340169bcd4241876b2e1e): 16411393 bytes on disk
I20260812 06:17:25.313054 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: UndoDeltaBlockGCOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4}
I20260812 06:17:25.313462 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling MajorDeltaCompactionOp(ba73322e522340169bcd4241876b2e1e): perf score=1.000000
I20260812 06:17:25.463340 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: MajorDeltaCompactionOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.150s	user 0.126s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":697,"lbm_read_time_us":9145,"lbm_reads_lt_1ms":460,"lbm_write_time_us":24647,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"thread_start_us":405,"threads_started":5,"update_count":2000}
I20260812 06:17:25.463948 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e): perf score=10.126437
I20260812 06:17:25.498682 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.035s	user 0.028s	sys 0.004s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14891,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:25.499161 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e): perf score=2.188937
I20260812 06:17:25.514449 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5196,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":500}
I20260812 06:17:25.515111 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling MajorDeltaCompactionOp(ba73322e522340169bcd4241876b2e1e): perf score=1.000000
I20260812 06:17:25.644637 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: MajorDeltaCompactionOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.129s	user 0.109s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":89,"lbm_read_time_us":7547,"lbm_reads_lt_1ms":468,"lbm_write_time_us":26427,"lbm_writes_lt_1ms":443,"mutex_wait_us":20,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13568,"update_count":2000}
I20260812 06:17:25.645183 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e): perf score=10.126437
I20260812 06:17:25.680095 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.035s	user 0.030s	sys 0.004s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15013,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:25.680585 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e): perf score=2.188937
I20260812 06:17:25.691628 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3918,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:25.692112 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling MajorDeltaCompactionOp(ba73322e522340169bcd4241876b2e1e): perf score=1.000000
I20260812 06:17:25.820590 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: MajorDeltaCompactionOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.128s	user 0.108s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":188,"lbm_read_time_us":9713,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23721,"lbm_writes_lt_1ms":443,"mutex_wait_us":28,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":26624,"update_count":2000}
I20260812 06:17:25.821195 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e): perf score=10.126437
I20260812 06:17:25.876613 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.055s	user 0.026s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17187,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:25.877139 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e): perf score=2.188937
I20260812 06:17:25.887574 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4074,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:25.888104 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling MajorDeltaCompactionOp(ba73322e522340169bcd4241876b2e1e): perf score=1.000000
I20260812 06:17:26.034807 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: MajorDeltaCompactionOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.147s	user 0.110s	sys 0.036s 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":257,"lbm_read_time_us":11082,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23393,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16512,"update_count":2000}
I20260812 06:17:26.035401 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e): perf score=10.126437
I20260812 06:17:26.079609 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.044s	user 0.027s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14700,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:26.080135 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e): perf score=2.188937
I20260812 06:17:26.092868 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.013s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5131,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:26.093314 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling MajorDeltaCompactionOp(ba73322e522340169bcd4241876b2e1e): perf score=1.000000
I20260812 06:17:26.221570 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: MajorDeltaCompactionOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.128s	user 0.115s	sys 0.012s 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":233,"lbm_read_time_us":9011,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24539,"lbm_writes_lt_1ms":443,"mutex_wait_us":73,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":2000}
I20260812 06:17:26.222349 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e): perf score=10.126437
I20260812 06:17:26.259249 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.037s	user 0.025s	sys 0.005s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":13558,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:26.259819 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling MajorDeltaCompactionOp(ba73322e522340169bcd4241876b2e1e): perf score=1.000000
I20260812 06:17:26.368644 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: MajorDeltaCompactionOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.109s	user 0.083s	sys 0.024s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569745,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":639,"lbm_read_time_us":5693,"lbm_reads_lt_1ms":363,"lbm_write_time_us":22588,"lbm_writes_lt_1ms":343,"mutex_wait_us":48,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":7936,"update_count":1500}
I20260812 06:17:26.369537 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e): perf score=10.126437
I20260812 06:17:26.417073 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.047s	user 0.031s	sys 0.004s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15805,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:26.417625 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e): perf score=2.188937
I20260812 06:17:26.430064 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4262,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:26.430620 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling MajorDeltaCompactionOp(ba73322e522340169bcd4241876b2e1e): perf score=1.000000
I20260812 06:17:26.569649 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: MajorDeltaCompactionOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.139s	user 0.089s	sys 0.049s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":339,"lbm_read_time_us":10843,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26617,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:17:26.570153 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e): perf score=10.126437
I20260812 06:17:26.603531 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.033s	user 0.018s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14068,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:26.604081 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling FlushMRSOp(ba73322e522340169bcd4241876b2e1e): perf score=1.000000
I20260812 06:17:26.644101 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: FlushMRSOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.040s	user 0.026s	sys 0.001s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":76,"dirs.run_cpu_time_us":246,"dirs.run_wall_time_us":1236,"drs_written":1,"lbm_read_time_us":43,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1810,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:26.645037 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling UndoDeltaBlockGCOp(ba73322e522340169bcd4241876b2e1e): 483 bytes on disk
I20260812 06:17:26.645849 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: UndoDeltaBlockGCOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":81,"lbm_reads_lt_1ms":4}
I20260812 06:17:26.646389 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e): perf score=3.181125
I20260812 06:17:26.664404 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.018s	user 0.012s	sys 0.005s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":6905,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:26.664844 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling LogGCOp(ba73322e522340169bcd4241876b2e1e): free 120553374 bytes of WAL
I20260812 06:17:26.665076 17747 log_reader.cc:385] T ba73322e522340169bcd4241876b2e1e: removed 12 log segments from log reader
I20260812 06:17:26.665123 17747 log.cc:1079] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/ba73322e522340169bcd4241876b2e1e/wal-000000003 (ops 12-16)
I20260812 06:17:26.665151 17747 log.cc:1079] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/ba73322e522340169bcd4241876b2e1e/wal-000000004 (ops 17-21)
I20260812 06:17:26.665218 17747 log.cc:1079] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/ba73322e522340169bcd4241876b2e1e/wal-000000005 (ops 22-26)
I20260812 06:17:26.665251 17747 log.cc:1079] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/ba73322e522340169bcd4241876b2e1e/wal-000000006 (ops 27-31)
I20260812 06:17:26.665320 17747 log.cc:1079] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/ba73322e522340169bcd4241876b2e1e/wal-000000007 (ops 32-36)
I20260812 06:17:26.665360 17747 log.cc:1079] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/ba73322e522340169bcd4241876b2e1e/wal-000000008 (ops 37-40)
I20260812 06:17:26.665400 17747 log.cc:1079] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/ba73322e522340169bcd4241876b2e1e/wal-000000009 (ops 41-45)
I20260812 06:17:26.665441 17747 log.cc:1079] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/ba73322e522340169bcd4241876b2e1e/wal-000000010 (ops 46-50)
I20260812 06:17:26.665479 17747 log.cc:1079] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/ba73322e522340169bcd4241876b2e1e/wal-000000011 (ops 51-55)
I20260812 06:17:26.665516 17747 log.cc:1079] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/ba73322e522340169bcd4241876b2e1e/wal-000000012 (ops 56-60)
I20260812 06:17:26.665552 17747 log.cc:1079] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/ba73322e522340169bcd4241876b2e1e/wal-000000013 (ops 61-64)
I20260812 06:17:26.665589 17747 log.cc:1079] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/ba73322e522340169bcd4241876b2e1e/wal-000000014 (ops 65-69)
I20260812 06:17:26.689690 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: LogGCOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.025s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:17:26.690094 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e): perf score=2.188937
I20260812 06:17:26.710534 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.020s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5484,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:26.711072 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling LogGCOp(ba73322e522340169bcd4241876b2e1e): free 12017983 bytes of WAL
I20260812 06:17:26.711311 17747 log_reader.cc:385] T ba73322e522340169bcd4241876b2e1e: removed 1 log segments from log reader
I20260812 06:17:26.711366 17747 log.cc:1079] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/ba73322e522340169bcd4241876b2e1e/wal-000000015 (ops 70-74)
I20260812 06:17:26.713843 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: LogGCOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:17:26.714126 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e): perf score=2.188937
I20260812 06:17:26.725045 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.011s	user 0.003s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3875,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:26.725607 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling MajorDeltaCompactionOp(ba73322e522340169bcd4241876b2e1e): perf score=1.000000
I20260812 06:17:26.899950 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: MajorDeltaCompactionOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.174s	user 0.143s	sys 0.025s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877328,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":725,"lbm_read_time_us":12064,"lbm_reads_lt_1ms":674,"lbm_write_time_us":32864,"lbm_writes_lt_1ms":643,"mutex_wait_us":19,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":15616,"thread_start_us":82,"threads_started":1,"update_count":3000}
I20260812 06:17:26.900488 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e): perf score=14.095187
I20260812 06:17:26.954908 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.054s	user 0.028s	sys 0.024s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":24483,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:26.955370 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e): perf score=2.188937
I20260812 06:17:26.966550 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4034,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:26.967182 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling MajorDeltaCompactionOp(ba73322e522340169bcd4241876b2e1e): perf score=1.000000
I20260812 06:17:27.124246 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: MajorDeltaCompactionOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.157s	user 0.113s	sys 0.040s 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":142,"lbm_read_time_us":10656,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31281,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:17:27.124811 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e): perf score=11.118625
I20260812 06:17:27.193593 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.069s	user 0.028s	sys 0.008s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":44867,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:17:27.194214 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e): perf score=6.157687
I20260812 06:17:27.221200 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.027s	user 0.008s	sys 0.012s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":8752,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:17:27.221705 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling MajorDeltaCompactionOp(ba73322e522340169bcd4241876b2e1e): perf score=1.000000
I20260812 06:17:27.377532 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: MajorDeltaCompactionOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.156s	user 0.135s	sys 0.020s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774693,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":554,"lbm_read_time_us":10160,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29273,"lbm_writes_lt_1ms":543,"mutex_wait_us":74,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":26112,"update_count":2500}
I20260812 06:17:27.378255 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e): perf score=14.095187
I20260812 06:17:27.428516 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.050s	user 0.034s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22860,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:27.429108 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e): perf score=2.188937
I20260812 06:17:27.440696 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.011s	user 0.009s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4010,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:27.441210 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling MajorDeltaCompactionOp(ba73322e522340169bcd4241876b2e1e): perf score=1.000000
I20260812 06:17:27.582440 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: MajorDeltaCompactionOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.141s	user 0.104s	sys 0.037s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":320,"lbm_read_time_us":10009,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27968,"lbm_writes_lt_1ms":543,"mutex_wait_us":90,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:17:27.583221 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e): perf score=10.126437
I20260812 06:17:27.625257 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.042s	user 0.012s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14479,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:27.625725 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e): perf score=2.188937
I20260812 06:17:27.636178 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3894,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:27.636673 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling MajorDeltaCompactionOp(ba73322e522340169bcd4241876b2e1e): perf score=1.000000
I20260812 06:17:27.761108 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: MajorDeltaCompactionOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.124s	user 0.104s	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":219,"lbm_read_time_us":10068,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22376,"lbm_writes_lt_1ms":443,"mutex_wait_us":60,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2000}
I20260812 06:17:27.761760 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e): perf score=10.126437
I20260812 06:17:27.818713 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.057s	user 0.028s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15576,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:27.819329 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e): perf score=2.188937
I20260812 06:17:27.830199 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4092,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:27.830651 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling MajorDeltaCompactionOp(ba73322e522340169bcd4241876b2e1e): perf score=1.000000
I20260812 06:17:27.983953 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: MajorDeltaCompactionOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.153s	user 0.109s	sys 0.044s 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":1031,"lbm_read_time_us":10863,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24445,"lbm_writes_lt_1ms":443,"mutex_wait_us":319,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2000}
I20260812 06:17:27.984594 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e): perf score=10.126437
I20260812 06:17:28.024719 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.040s	user 0.024s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15050,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:28.025195 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e): perf score=2.188937
I20260812 06:17:28.035562 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3902,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:28.036428 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling FlushMRSOp(ba73322e522340169bcd4241876b2e1e): perf score=1.000000
I20260812 06:17:28.068732 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: FlushMRSOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.032s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":70,"dirs.run_cpu_time_us":238,"dirs.run_wall_time_us":1166,"drs_written":1,"lbm_read_time_us":43,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1784,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:28.069429 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling LogGCOp(ba73322e522340169bcd4241876b2e1e): free 108535397 bytes of WAL
I20260812 06:17:28.069661 17747 log_reader.cc:385] T ba73322e522340169bcd4241876b2e1e: removed 11 log segments from log reader
I20260812 06:17:28.069706 17747 log.cc:1079] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/ba73322e522340169bcd4241876b2e1e/wal-000000016 (ops 75-79)
I20260812 06:17:28.069734 17747 log.cc:1079] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/ba73322e522340169bcd4241876b2e1e/wal-000000017 (ops 80-84)
I20260812 06:17:28.069802 17747 log.cc:1079] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/ba73322e522340169bcd4241876b2e1e/wal-000000018 (ops 85-88)
I20260812 06:17:28.069844 17747 log.cc:1079] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/ba73322e522340169bcd4241876b2e1e/wal-000000019 (ops 89-93)
I20260812 06:17:28.069885 17747 log.cc:1079] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/ba73322e522340169bcd4241876b2e1e/wal-000000020 (ops 94-98)
I20260812 06:17:28.069948 17747 log.cc:1079] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/ba73322e522340169bcd4241876b2e1e/wal-000000021 (ops 99-103)
I20260812 06:17:28.069990 17747 log.cc:1079] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/ba73322e522340169bcd4241876b2e1e/wal-000000022 (ops 104-108)
I20260812 06:17:28.070029 17747 log.cc:1079] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/ba73322e522340169bcd4241876b2e1e/wal-000000023 (ops 109-112)
I20260812 06:17:28.070070 17747 log.cc:1079] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/ba73322e522340169bcd4241876b2e1e/wal-000000024 (ops 113-117)
I20260812 06:17:28.070109 17747 log.cc:1079] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/ba73322e522340169bcd4241876b2e1e/wal-000000025 (ops 118-122)
I20260812 06:17:28.070152 17747 log.cc:1079] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/ba73322e522340169bcd4241876b2e1e/wal-000000026 (ops 123-127)
I20260812 06:17:28.093816 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: LogGCOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.024s	user 0.003s	sys 0.019s Metrics: {}
I20260812 06:17:28.094226 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling UndoDeltaBlockGCOp(ba73322e522340169bcd4241876b2e1e): 462 bytes on disk
I20260812 06:17:28.094723 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: UndoDeltaBlockGCOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":78,"lbm_reads_lt_1ms":4}
I20260812 06:17:28.095203 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e): perf score=3.181125
I20260812 06:17:28.114239 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.019s	user 0.006s	sys 0.010s Metrics: {"bytes_written":4512901,"delete_count":0,"lbm_write_time_us":4613,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:28.114801 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e): perf score=2.188937
I20260812 06:17:28.124782 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3780,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:28.125420 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling MajorDeltaCompactionOp(ba73322e522340169bcd4241876b2e1e): perf score=1.000000
I20260812 06:17:28.327363 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: MajorDeltaCompactionOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.202s	user 0.155s	sys 0.044s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877328,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":2694,"lbm_read_time_us":15216,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34632,"lbm_writes_lt_1ms":643,"mutex_wait_us":52,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":14464,"thread_start_us":88,"threads_started":1,"update_count":3000}
I20260812 06:17:28.328084 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e): perf score=14.095187
I20260812 06:17:28.388401 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.060s	user 0.036s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22670,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:28.389245 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e): perf score=2.188937
I20260812 06:17:28.400039 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4392,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:28.400470 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling MajorDeltaCompactionOp(ba73322e522340169bcd4241876b2e1e): perf score=1.000000
I20260812 06:17:28.580952 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: MajorDeltaCompactionOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.180s	user 0.147s	sys 0.032s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":78,"lbm_read_time_us":13157,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30947,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2500}
I20260812 06:17:28.581772 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e): perf score=10.126437
I20260812 06:17:28.623096 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.041s	user 0.019s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18423,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:28.623741 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e): perf score=2.188937
I20260812 06:17:28.634528 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4238,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:28.635043 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling MajorDeltaCompactionOp(ba73322e522340169bcd4241876b2e1e): perf score=1.000000
I20260812 06:17:28.769500 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: MajorDeltaCompactionOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.134s	user 0.114s	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":128,"lbm_read_time_us":9757,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24009,"lbm_writes_lt_1ms":443,"mutex_wait_us":25,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12288,"update_count":2000}
I20260812 06:17:28.770107 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e): perf score=10.126437
I20260812 06:17:28.820573 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.050s	user 0.027s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15317,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:28.821251 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e): perf score=2.188937
I20260812 06:17:28.836948 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.015s	user 0.009s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6086,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:28.837672 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling MajorDeltaCompactionOp(ba73322e522340169bcd4241876b2e1e): perf score=1.000000
I20260812 06:17:28.955058 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: MajorDeltaCompactionOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.117s	user 0.095s	sys 0.021s 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":177,"lbm_read_time_us":7680,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22539,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16768,"update_count":2000}
I20260812 06:17:28.955796 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e): perf score=10.126437
I20260812 06:17:29.004899 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.049s	user 0.039s	sys 0.000s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17602,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:29.005419 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e): perf score=2.188937
I20260812 06:17:29.016803 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4137,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:29.017278 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling MajorDeltaCompactionOp(ba73322e522340169bcd4241876b2e1e): perf score=1.000000
I20260812 06:17:29.138223 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: MajorDeltaCompactionOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.121s	user 0.093s	sys 0.028s 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":244,"lbm_read_time_us":8399,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23264,"lbm_writes_lt_1ms":443,"mutex_wait_us":21,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6784,"update_count":2000}
I20260812 06:17:29.138829 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e): perf score=10.126437
I20260812 06:17:29.188071 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.049s	user 0.027s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16603,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":1500}
I20260812 06:17:29.188709 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e): perf score=2.188937
I20260812 06:17:29.199887 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4367,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:29.200348 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling MajorDeltaCompactionOp(ba73322e522340169bcd4241876b2e1e): perf score=1.000000
I20260812 06:17:29.344121 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: MajorDeltaCompactionOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.144s	user 0.087s	sys 0.056s 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":1184,"lbm_read_time_us":11540,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23521,"lbm_writes_lt_1ms":443,"mutex_wait_us":300,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16000,"update_count":2000}
I20260812 06:17:29.344686 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e): perf score=10.126437
I20260812 06:17:29.385936 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.041s	user 0.022s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18699,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:29.386401 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e): perf score=2.188937
I20260812 06:17:29.397846 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4072,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:29.398370 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling MajorDeltaCompactionOp(ba73322e522340169bcd4241876b2e1e): perf score=1.000000
I20260812 06:17:29.519243 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: MajorDeltaCompactionOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.121s	user 0.109s	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":394,"lbm_read_time_us":8803,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22383,"lbm_writes_lt_1ms":443,"mutex_wait_us":38,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9344,"update_count":2000}
I20260812 06:17:29.519869 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e): perf score=10.126437
I20260812 06:17:29.567130 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.047s	user 0.014s	sys 0.021s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":16684,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:29.567817 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e): perf score=2.188937
I20260812 06:17:29.583279 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5771,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:29.584137 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling FlushMRSOp(ba73322e522340169bcd4241876b2e1e): perf score=1.000000
I20260812 06:17:29.612977 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: FlushMRSOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.029s	user 0.023s	sys 0.004s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":66,"dirs.run_cpu_time_us":208,"dirs.run_wall_time_us":1195,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1633,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:29.613852 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling LogGCOp(ba73322e522340169bcd4241876b2e1e): free 132571636 bytes of WAL
I20260812 06:17:29.614099 17747 log_reader.cc:385] T ba73322e522340169bcd4241876b2e1e: removed 13 log segments from log reader
I20260812 06:17:29.614167 17747 log.cc:1079] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/ba73322e522340169bcd4241876b2e1e/wal-000000027 (ops 128-132)
I20260812 06:17:29.614216 17747 log.cc:1079] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/ba73322e522340169bcd4241876b2e1e/wal-000000028 (ops 133-137)
I20260812 06:17:29.614275 17747 log.cc:1079] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/ba73322e522340169bcd4241876b2e1e/wal-000000029 (ops 138-142)
I20260812 06:17:29.614317 17747 log.cc:1079] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/ba73322e522340169bcd4241876b2e1e/wal-000000030 (ops 143-147)
I20260812 06:17:29.614358 17747 log.cc:1079] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/ba73322e522340169bcd4241876b2e1e/wal-000000031 (ops 148-152)
I20260812 06:17:29.614398 17747 log.cc:1079] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/ba73322e522340169bcd4241876b2e1e/wal-000000032 (ops 153-156)
I20260812 06:17:29.614439 17747 log.cc:1079] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/ba73322e522340169bcd4241876b2e1e/wal-000000033 (ops 157-161)
I20260812 06:17:29.614480 17747 log.cc:1079] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/ba73322e522340169bcd4241876b2e1e/wal-000000034 (ops 162-166)
I20260812 06:17:29.614519 17747 log.cc:1079] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/ba73322e522340169bcd4241876b2e1e/wal-000000035 (ops 167-171)
I20260812 06:17:29.614562 17747 log.cc:1079] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/ba73322e522340169bcd4241876b2e1e/wal-000000036 (ops 172-176)
I20260812 06:17:29.614600 17747 log.cc:1079] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/ba73322e522340169bcd4241876b2e1e/wal-000000037 (ops 177-180)
I20260812 06:17:29.614639 17747 log.cc:1079] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/ba73322e522340169bcd4241876b2e1e/wal-000000038 (ops 181-185)
I20260812 06:17:29.614679 17747 log.cc:1079] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/ba73322e522340169bcd4241876b2e1e/wal-000000039 (ops 186-190)
I20260812 06:17:29.643567 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: LogGCOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.030s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:17:29.644349 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e): perf score=4.173312
I20260812 06:17:29.661026 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.016s	user 0.011s	sys 0.004s Metrics: {"bytes_written":5415441,"delete_count":0,"lbm_write_time_us":6595,"lbm_writes_lt_1ms":135,"reinsert_count":0,"update_count":660}
I20260812 06:17:29.661562 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling UndoDeltaBlockGCOp(ba73322e522340169bcd4241876b2e1e): 483 bytes on disk
I20260812 06:17:29.662139 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: UndoDeltaBlockGCOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":67,"lbm_reads_lt_1ms":4}
I20260812 06:17:29.662709 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e): perf score=1.196750
I20260812 06:17:29.672549 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":2789855,"delete_count":0,"lbm_write_time_us":2873,"lbm_writes_lt_1ms":71,"reinsert_count":0,"update_count":340}
I20260812 06:17:29.673152 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling MajorDeltaCompactionOp(ba73322e522340169bcd4241876b2e1e): perf score=1.000000
I20260812 06:17:29.798635 17588 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.839s	user 1.882s	sys 0.102s
I20260812 06:17:29.833376 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: MajorDeltaCompactionOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.160s	user 0.114s	sys 0.044s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877313,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":10794,"lbm_reads_lt_1ms":666,"lbm_write_time_us":34997,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":3000}
I20260812 06:17:29.833895 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e): perf score=10.126437
I20260812 06:17:29.862068 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: FlushDeltaMemStoresOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.028s	user 0.013s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12286,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:29.862586 17852 maintenance_manager.cc:419] P 341598efd47a40c8922f41c064400f38: Scheduling MajorDeltaCompactionOp(ba73322e522340169bcd4241876b2e1e): perf score=1.000000
I20260812 06:17:29.874027 17588 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.075s	user 0.003s	sys 0.000s
I20260812 06:17:29.874956 17588 tablet_server.cc:179] TabletServer@127.17.45.1:0 shutting down...
I20260812 06:17:29.961234 17747 maintenance_manager.cc:643] P 341598efd47a40c8922f41c064400f38: MajorDeltaCompactionOp(ba73322e522340169bcd4241876b2e1e) complete. Timing: real 0.098s	user 0.072s	sys 0.025s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569746,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":493,"lbm_read_time_us":8344,"lbm_reads_lt_1ms":367,"lbm_write_time_us":19261,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":342,"peak_mem_usage":38262756,"reinsert_count":0,"update_count":1500}
I20260812 06:17:29.962419 17588 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:29.962833 17588 tablet_replica.cc:333] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38: stopping tablet replica
I20260812 06:17:29.963083 17588 raft_consensus.cc:2243] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:29.963362 17588 raft_consensus.cc:2272] T ba73322e522340169bcd4241876b2e1e P 341598efd47a40c8922f41c064400f38 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:29.979032 17588 tablet_server.cc:196] TabletServer@127.17.45.1:0 shutdown complete.
I20260812 06:17:29.995101 17588 master.cc:562] Master@127.17.45.62:36735 shutting down...
I20260812 06:17:29.999466 17588 raft_consensus.cc:2243] T 00000000000000000000000000000000 P a53ff167692243558b672d063ae0af85 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:29.999711 17588 raft_consensus.cc:2272] T 00000000000000000000000000000000 P a53ff167692243558b672d063ae0af85 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:29.999845 17588 tablet_replica.cc:333] T 00000000000000000000000000000000 P a53ff167692243558b672d063ae0af85: stopping tablet replica
I20260812 06:17:30.013484 17588 master.cc:584] Master@127.17.45.62:36735 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5432 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:30.114415 17588 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.17.45.62:37657
I20260812 06:17:30.114871 17588 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:30.117033 17894 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:17:30.117100 17895 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:30.117250 17588 server_base.cc:1061] running on GCE node
W20260812 06:17:30.117126 17898 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:17:30.117465 17588 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:30.117506 17588 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:17:30.117520 17588 hybrid_clock.cc:648] HybridClock initialized: now 1786515450117520 us; error 0 us; skew 500 ppm
I20260812 06:17:30.118391 17588 webserver.cc:533] Webserver started at http://127.17.45.62:41491/ using document root <none> and password file <none>
I20260812 06:17:30.118572 17588 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:30.118650 17588 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:30.118736 17588 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:30.119154 17588 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444658860-17588-0/minicluster-data/master-0-root/instance:
uuid: "8d575546660f4f1487d192884fe5cf42"
format_stamp: "Formatted at 2026-08-12 06:17:30 on dist-test-slave-mjjr"
I20260812 06:17:30.120743 17588 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:17:30.121647 17906 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:17:30.121892 17588 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:17:30.121966 17588 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444658860-17588-0/minicluster-data/master-0-root
uuid: "8d575546660f4f1487d192884fe5cf42"
format_stamp: "Formatted at 2026-08-12 06:17:30 on dist-test-slave-mjjr"
I20260812 06:17:30.122022 17588 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444658860-17588-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444658860-17588-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444658860-17588-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:17:30.129449 17588 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:30.129751 17588 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:30.133627 17588 rpc_server.cc:307] RPC server started. Bound to: 127.17.45.62:37657
I20260812 06:17:30.134369 17986 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.17.45.62:37657 every 8 connection(s)
I20260812 06:17:30.134819 17988 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:17:30.136668 17988 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 8d575546660f4f1487d192884fe5cf42: Bootstrap starting.
I20260812 06:17:30.137422 17988 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 8d575546660f4f1487d192884fe5cf42: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:30.138396 17988 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 8d575546660f4f1487d192884fe5cf42: No bootstrap required, opened a new log
I20260812 06:17:30.138784 17988 raft_consensus.cc:359] T 00000000000000000000000000000000 P 8d575546660f4f1487d192884fe5cf42 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8d575546660f4f1487d192884fe5cf42" member_type: VOTER }
I20260812 06:17:30.138868 17988 raft_consensus.cc:385] T 00000000000000000000000000000000 P 8d575546660f4f1487d192884fe5cf42 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:30.138922 17988 raft_consensus.cc:740] T 00000000000000000000000000000000 P 8d575546660f4f1487d192884fe5cf42 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 8d575546660f4f1487d192884fe5cf42, State: Initialized, Role: FOLLOWER
I20260812 06:17:30.139097 17988 consensus_queue.cc:260] T 00000000000000000000000000000000 P 8d575546660f4f1487d192884fe5cf42 [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: "8d575546660f4f1487d192884fe5cf42" member_type: VOTER }
I20260812 06:17:30.139170 17988 raft_consensus.cc:399] T 00000000000000000000000000000000 P 8d575546660f4f1487d192884fe5cf42 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:30.139223 17988 raft_consensus.cc:493] T 00000000000000000000000000000000 P 8d575546660f4f1487d192884fe5cf42 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:30.139285 17988 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 8d575546660f4f1487d192884fe5cf42 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:30.140055 17988 raft_consensus.cc:515] T 00000000000000000000000000000000 P 8d575546660f4f1487d192884fe5cf42 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8d575546660f4f1487d192884fe5cf42" member_type: VOTER }
I20260812 06:17:30.140197 17988 leader_election.cc:304] T 00000000000000000000000000000000 P 8d575546660f4f1487d192884fe5cf42 [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: 8d575546660f4f1487d192884fe5cf42; no voters: 
I20260812 06:17:30.140398 17988 leader_election.cc:290] T 00000000000000000000000000000000 P 8d575546660f4f1487d192884fe5cf42 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:30.140523 17991 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 8d575546660f4f1487d192884fe5cf42 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:30.140749 17991 raft_consensus.cc:697] T 00000000000000000000000000000000 P 8d575546660f4f1487d192884fe5cf42 [term 1 LEADER]: Becoming Leader. State: Replica: 8d575546660f4f1487d192884fe5cf42, State: Running, Role: LEADER
I20260812 06:17:30.140872 17988 sys_catalog.cc:565] T 00000000000000000000000000000000 P 8d575546660f4f1487d192884fe5cf42 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:30.140923 17991 consensus_queue.cc:237] T 00000000000000000000000000000000 P 8d575546660f4f1487d192884fe5cf42 [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: "8d575546660f4f1487d192884fe5cf42" member_type: VOTER }
I20260812 06:17:30.141403 17996 sys_catalog.cc:455] T 00000000000000000000000000000000 P 8d575546660f4f1487d192884fe5cf42 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 8d575546660f4f1487d192884fe5cf42. Latest consensus state: current_term: 1 leader_uuid: "8d575546660f4f1487d192884fe5cf42" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8d575546660f4f1487d192884fe5cf42" member_type: VOTER } }
I20260812 06:17:30.141434 17994 sys_catalog.cc:455] T 00000000000000000000000000000000 P 8d575546660f4f1487d192884fe5cf42 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "8d575546660f4f1487d192884fe5cf42" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8d575546660f4f1487d192884fe5cf42" member_type: VOTER } }
I20260812 06:17:30.141549 17996 sys_catalog.cc:458] T 00000000000000000000000000000000 P 8d575546660f4f1487d192884fe5cf42 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:30.141566 17994 sys_catalog.cc:458] T 00000000000000000000000000000000 P 8d575546660f4f1487d192884fe5cf42 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:30.142184 18002 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:30.142958 18002 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:30.143191 17588 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:30.144912 18002 catalog_manager.cc:1383] Generated new cluster ID: 34c2d87303cc4faa86554a9a60cf206c
I20260812 06:17:30.144972 18002 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:30.156965 18002 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:30.157480 18002 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:30.167263 18002 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 8d575546660f4f1487d192884fe5cf42: Generated new TSK 0
I20260812 06:17:30.167444 18002 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:30.175755 17588 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:30.177747 18025 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:17:30.177788 18022 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:17:30.177834 18023 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:30.177930 17588 server_base.cc:1061] running on GCE node
I20260812 06:17:30.178185 17588 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:30.178226 17588 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:17:30.178241 17588 hybrid_clock.cc:648] HybridClock initialized: now 1786515450178241 us; error 0 us; skew 500 ppm
I20260812 06:17:30.179073 17588 webserver.cc:533] Webserver started at http://127.17.45.1:38785/ using document root <none> and password file <none>
I20260812 06:17:30.179248 17588 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:30.179314 17588 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:30.179399 17588 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:30.179840 17588 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444658860-17588-0/minicluster-data/ts-0-root/instance:
uuid: "f96a0c86748f46d3b28b73289a242ff6"
format_stamp: "Formatted at 2026-08-12 06:17:30 on dist-test-slave-mjjr"
I20260812 06:17:30.181310 17588 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:30.182204 18034 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:17:30.182462 17588 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:30.182554 17588 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444658860-17588-0/minicluster-data/ts-0-root
uuid: "f96a0c86748f46d3b28b73289a242ff6"
format_stamp: "Formatted at 2026-08-12 06:17:30 on dist-test-slave-mjjr"
I20260812 06:17:30.182648 17588 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444658860-17588-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444658860-17588-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444658860-17588-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:17:30.197335 17588 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:30.197722 17588 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:30.198046 17588 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:30.198519 17588 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:30.198578 17588 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:30.198640 17588 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:30.198675 17588 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:30.202976 17588 rpc_server.cc:307] RPC server started. Bound to: 127.17.45.1:41843
I20260812 06:17:30.204617 18132 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.17.45.1:41843 every 8 connection(s)
I20260812 06:17:30.213176 18133 heartbeater.cc:344] Connected to a master server at 127.17.45.62:37657
I20260812 06:17:30.213331 18133 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:30.213601 18133 heartbeater.cc:507] Master 127.17.45.62:37657 requested a full tablet report, sending...
I20260812 06:17:30.214337 17934 ts_manager.cc:194] Registered new tserver with Master: f96a0c86748f46d3b28b73289a242ff6 (127.17.45.1:41843)
I20260812 06:17:30.214915 17588 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011120343s
I20260812 06:17:30.215093 17934 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:49388
I20260812 06:17:30.222147 17934 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:49398:
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:17:30.231830 18083 tablet_service.cc:1511] Processing CreateTablet for tablet 24c408aadef84c8e868d81350bd8ac61 (DEFAULT_TABLE table=heavy-update-compaction-test [id=f2fb1e963e32454db151569003d2e878]), partition=
I20260812 06:17:30.232103 18083 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 24c408aadef84c8e868d81350bd8ac61. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:30.234230 18157 tablet_bootstrap.cc:492] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6: Bootstrap starting.
I20260812 06:17:30.235137 18157 tablet_bootstrap.cc:654] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:30.236163 18157 tablet_bootstrap.cc:492] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6: No bootstrap required, opened a new log
I20260812 06:17:30.236238 18157 ts_tablet_manager.cc:1403] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:17:30.236575 18157 raft_consensus.cc:359] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f96a0c86748f46d3b28b73289a242ff6" member_type: VOTER last_known_addr { host: "127.17.45.1" port: 41843 } }
I20260812 06:17:30.236661 18157 raft_consensus.cc:385] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:30.236683 18157 raft_consensus.cc:740] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: f96a0c86748f46d3b28b73289a242ff6, State: Initialized, Role: FOLLOWER
I20260812 06:17:30.236832 18157 consensus_queue.cc:260] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6 [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: "f96a0c86748f46d3b28b73289a242ff6" member_type: VOTER last_known_addr { host: "127.17.45.1" port: 41843 } }
I20260812 06:17:30.236928 18157 raft_consensus.cc:399] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:30.236971 18157 raft_consensus.cc:493] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:30.237020 18157 raft_consensus.cc:3060] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:30.237979 18157 raft_consensus.cc:515] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f96a0c86748f46d3b28b73289a242ff6" member_type: VOTER last_known_addr { host: "127.17.45.1" port: 41843 } }
I20260812 06:17:30.238128 18157 leader_election.cc:304] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6 [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: f96a0c86748f46d3b28b73289a242ff6; no voters: 
I20260812 06:17:30.238354 18157 leader_election.cc:290] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:30.238502 18160 raft_consensus.cc:2804] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:30.238708 18133 heartbeater.cc:499] Master 127.17.45.62:37657 was elected leader, sending a full tablet report...
I20260812 06:17:30.238732 18160 raft_consensus.cc:697] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6 [term 1 LEADER]: Becoming Leader. State: Replica: f96a0c86748f46d3b28b73289a242ff6, State: Running, Role: LEADER
I20260812 06:17:30.238713 18157 ts_tablet_manager.cc:1434] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:17:30.238891 18160 consensus_queue.cc:237] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6 [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: "f96a0c86748f46d3b28b73289a242ff6" member_type: VOTER last_known_addr { host: "127.17.45.1" port: 41843 } }
I20260812 06:17:30.240170 17934 catalog_manager.cc:5719] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6 reported cstate change: term changed from 0 to 1, leader changed from <none> to f96a0c86748f46d3b28b73289a242ff6 (127.17.45.1). New cstate: current_term: 1 leader_uuid: "f96a0c86748f46d3b28b73289a242ff6" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f96a0c86748f46d3b28b73289a242ff6" member_type: VOTER last_known_addr { host: "127.17.45.1" port: 41843 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:30.300609 17588 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.053s	user 0.023s	sys 0.000s
I20260812 06:17:30.455252 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling FlushMRSOp(24c408aadef84c8e868d81350bd8ac61): perf score=19.054940
I20260812 06:17:30.613317 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: FlushMRSOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.158s	user 0.132s	sys 0.023s Metrics: {"bytes_written":12717739,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":111,"dirs.run_cpu_time_us":194,"dirs.run_wall_time_us":866,"drs_written":1,"lbm_read_time_us":113,"lbm_reads_lt_1ms":4,"lbm_write_time_us":37368,"lbm_writes_lt_1ms":767,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":7040,"update_count":1550}
I20260812 06:17:30.614131 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling LogGCOp(24c408aadef84c8e868d81350bd8ac61): free 20290830 bytes of WAL
I20260812 06:17:30.614362 18041 log_reader.cc:385] T 24c408aadef84c8e868d81350bd8ac61: removed 2 log segments from log reader
I20260812 06:17:30.614419 18041 log.cc:1079] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/24c408aadef84c8e868d81350bd8ac61/wal-000000001 (ops 1-6)
I20260812 06:17:30.614462 18041 log.cc:1079] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/24c408aadef84c8e868d81350bd8ac61/wal-000000002 (ops 7-10)
I20260812 06:17:30.619247 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: LogGCOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.005s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:17:30.619577 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61): perf score=2.188937
I20260812 06:17:30.639735 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.020s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3962,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:30.640223 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61): perf score=2.188937
I20260812 06:17:30.653968 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.014s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5488,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:30.654474 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling UndoDeltaBlockGCOp(24c408aadef84c8e868d81350bd8ac61): 16411398 bytes on disk
I20260812 06:17:30.654984 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: UndoDeltaBlockGCOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4}
I20260812 06:17:30.655475 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling MajorDeltaCompactionOp(24c408aadef84c8e868d81350bd8ac61): perf score=1.000000
I20260812 06:17:30.850737 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: MajorDeltaCompactionOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.195s	user 0.111s	sys 0.076s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774803,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":814,"lbm_read_time_us":13415,"lbm_reads_lt_1ms":569,"lbm_write_time_us":29652,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6400,"thread_start_us":355,"threads_started":5,"update_count":2500}
I20260812 06:17:30.851472 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61): perf score=14.095187
I20260812 06:17:30.899262 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.048s	user 0.029s	sys 0.015s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20849,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:30.899773 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61): perf score=2.188937
I20260812 06:17:30.921289 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.021s	user 0.009s	sys 0.011s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4183,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:30.921792 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling MajorDeltaCompactionOp(24c408aadef84c8e868d81350bd8ac61): perf score=1.000000
I20260812 06:17:31.101289 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: MajorDeltaCompactionOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.179s	user 0.121s	sys 0.055s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":620,"lbm_read_time_us":11926,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28091,"lbm_writes_lt_1ms":543,"mutex_wait_us":51,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12672,"update_count":2500}
I20260812 06:17:31.102011 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61): perf score=14.095187
I20260812 06:17:31.150028 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.048s	user 0.018s	sys 0.027s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21741,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:31.150542 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61): perf score=2.188937
I20260812 06:17:31.166352 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.016s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6141,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:31.166957 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling MajorDeltaCompactionOp(24c408aadef84c8e868d81350bd8ac61): perf score=1.000000
I20260812 06:17:31.371160 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: MajorDeltaCompactionOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.204s	user 0.143s	sys 0.049s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":140,"lbm_read_time_us":12809,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33446,"lbm_writes_lt_1ms":543,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":84992,"update_count":2500}
I20260812 06:17:31.371846 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61): perf score=14.095187
I20260812 06:17:31.430375 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.058s	user 0.025s	sys 0.022s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22117,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:31.430954 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61): perf score=2.188937
I20260812 06:17:31.443724 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.013s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4700,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:31.444226 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling MajorDeltaCompactionOp(24c408aadef84c8e868d81350bd8ac61): perf score=1.000000
I20260812 06:17:31.609939 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: MajorDeltaCompactionOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.166s	user 0.121s	sys 0.040s 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":526,"lbm_read_time_us":12474,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33389,"lbm_writes_lt_1ms":543,"mutex_wait_us":291,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":17024,"update_count":2500}
I20260812 06:17:31.611019 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61): perf score=11.118625
I20260812 06:17:31.654582 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.043s	user 0.013s	sys 0.023s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":18909,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":310,"reinsert_count":0,"update_count":1550}
I20260812 06:17:31.655112 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61): perf score=2.188937
I20260812 06:17:31.665835 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4192,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:31.666278 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61): perf score=2.188937
I20260812 06:17:31.675994 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3618,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:31.676467 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling MajorDeltaCompactionOp(24c408aadef84c8e868d81350bd8ac61): perf score=1.000000
I20260812 06:17:31.835940 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: MajorDeltaCompactionOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.159s	user 0.104s	sys 0.049s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774800,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":857,"lbm_read_time_us":12736,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29407,"lbm_writes_lt_1ms":543,"mutex_wait_us":325,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12160,"update_count":2500}
I20260812 06:17:31.836748 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61): perf score=14.095187
I20260812 06:17:31.886606 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.050s	user 0.029s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21394,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:31.887074 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61): perf score=2.188937
I20260812 06:17:31.898237 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4145,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:31.898893 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling FlushMRSOp(24c408aadef84c8e868d81350bd8ac61): perf score=1.000000
I20260812 06:17:31.931269 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: FlushMRSOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.032s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":258,"dirs.run_wall_time_us":1327,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1494,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30,"spinlock_wait_cycles":4992}
I20260812 06:17:31.931957 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling LogGCOp(24c408aadef84c8e868d81350bd8ac61): free 120553371 bytes of WAL
I20260812 06:17:31.932178 18041 log_reader.cc:385] T 24c408aadef84c8e868d81350bd8ac61: removed 12 log segments from log reader
I20260812 06:17:31.932221 18041 log.cc:1079] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/24c408aadef84c8e868d81350bd8ac61/wal-000000003 (ops 11-15)
I20260812 06:17:31.932250 18041 log.cc:1079] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/24c408aadef84c8e868d81350bd8ac61/wal-000000004 (ops 16-20)
I20260812 06:17:31.932322 18041 log.cc:1079] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/24c408aadef84c8e868d81350bd8ac61/wal-000000005 (ops 21-24)
I20260812 06:17:31.932372 18041 log.cc:1079] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/24c408aadef84c8e868d81350bd8ac61/wal-000000006 (ops 25-29)
I20260812 06:17:31.932415 18041 log.cc:1079] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/24c408aadef84c8e868d81350bd8ac61/wal-000000007 (ops 30-34)
I20260812 06:17:31.932482 18041 log.cc:1079] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/24c408aadef84c8e868d81350bd8ac61/wal-000000008 (ops 35-39)
I20260812 06:17:31.932523 18041 log.cc:1079] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/24c408aadef84c8e868d81350bd8ac61/wal-000000009 (ops 40-44)
I20260812 06:17:31.932564 18041 log.cc:1079] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/24c408aadef84c8e868d81350bd8ac61/wal-000000010 (ops 45-48)
I20260812 06:17:31.932610 18041 log.cc:1079] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/24c408aadef84c8e868d81350bd8ac61/wal-000000011 (ops 49-53)
I20260812 06:17:31.932651 18041 log.cc:1079] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/24c408aadef84c8e868d81350bd8ac61/wal-000000012 (ops 54-58)
I20260812 06:17:31.932693 18041 log.cc:1079] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/24c408aadef84c8e868d81350bd8ac61/wal-000000013 (ops 59-63)
I20260812 06:17:31.932732 18041 log.cc:1079] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/24c408aadef84c8e868d81350bd8ac61/wal-000000014 (ops 64-68)
I20260812 06:17:31.959789 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: LogGCOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.028s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:17:31.960268 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61): perf score=2.188937
I20260812 06:17:31.975586 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.015s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3994,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:31.976087 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61): perf score=2.188937
I20260812 06:17:31.986651 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4116,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:31.987080 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling UndoDeltaBlockGCOp(24c408aadef84c8e868d81350bd8ac61): 473 bytes on disk
I20260812 06:17:31.987565 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: UndoDeltaBlockGCOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":67,"lbm_reads_lt_1ms":4}
I20260812 06:17:31.988157 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling MajorDeltaCompactionOp(24c408aadef84c8e868d81350bd8ac61): perf score=1.000000
I20260812 06:17:32.191787 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: MajorDeltaCompactionOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.203s	user 0.157s	sys 0.045s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979750,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":946,"lbm_read_time_us":15288,"lbm_reads_lt_1ms":774,"lbm_write_time_us":42169,"lbm_writes_lt_1ms":743,"mutex_wait_us":310,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":13952,"thread_start_us":120,"threads_started":1,"update_count":3500}
I20260812 06:17:32.192543 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61): perf score=14.095187
I20260812 06:17:32.235904 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.043s	user 0.023s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18803,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:32.236526 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61): perf score=2.188937
I20260812 06:17:32.263147 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.026s	user 0.009s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6067,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:32.263602 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61): perf score=2.188937
I20260812 06:17:32.274309 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4130,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:32.274773 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling MajorDeltaCompactionOp(24c408aadef84c8e868d81350bd8ac61): perf score=1.000000
I20260812 06:17:32.441653 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: MajorDeltaCompactionOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.167s	user 0.126s	sys 0.040s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877218,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1075,"lbm_read_time_us":12614,"lbm_reads_lt_1ms":673,"lbm_write_time_us":33758,"lbm_writes_lt_1ms":643,"mutex_wait_us":324,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":13568,"update_count":3000}
I20260812 06:17:32.442324 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61): perf score=14.095187
I20260812 06:17:32.490157 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.048s	user 0.025s	sys 0.020s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":21245,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:32.490669 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61): perf score=2.188937
I20260812 06:17:32.502951 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4219,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:32.503576 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling MajorDeltaCompactionOp(24c408aadef84c8e868d81350bd8ac61): perf score=1.000000
I20260812 06:17:32.663760 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: MajorDeltaCompactionOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.160s	user 0.109s	sys 0.035s 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":11162,"dirs.run_cpu_time_us":627,"dirs.run_wall_time_us":3787,"lbm_read_time_us":10642,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29388,"lbm_writes_lt_1ms":543,"mutex_wait_us":3535,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4096,"update_count":2500}
I20260812 06:17:32.664551 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61): perf score=14.095187
I20260812 06:17:32.716225 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.051s	user 0.036s	sys 0.008s Metrics: {"bytes_written":16409906,"delete_count":0,"lbm_write_time_us":20217,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:32.716818 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61): perf score=2.188937
I20260812 06:17:32.727751 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4164,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:32.728188 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling MajorDeltaCompactionOp(24c408aadef84c8e868d81350bd8ac61): perf score=1.000000
I20260812 06:17:32.921729 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: MajorDeltaCompactionOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.193s	user 0.110s	sys 0.076s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774693,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":524,"lbm_read_time_us":13293,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32756,"lbm_writes_lt_1ms":543,"mutex_wait_us":109,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16256,"update_count":2500}
I20260812 06:17:32.922322 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61): perf score=14.095187
I20260812 06:17:32.965781 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.043s	user 0.025s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19604,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:32.966287 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling MajorDeltaCompactionOp(24c408aadef84c8e868d81350bd8ac61): perf score=1.000000
I20260812 06:17:33.133957 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: MajorDeltaCompactionOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.167s	user 0.135s	sys 0.032s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":716,"lbm_read_time_us":12003,"lbm_reads_lt_1ms":467,"lbm_write_time_us":26037,"lbm_writes_lt_1ms":443,"mutex_wait_us":79,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8320,"update_count":2000}
I20260812 06:17:33.135010 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61): perf score=11.118625
I20260812 06:17:33.174222 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.039s	user 0.017s	sys 0.020s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17516,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:33.174762 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61): perf score=2.188937
I20260812 06:17:33.185639 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4019,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:33.186260 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling MajorDeltaCompactionOp(24c408aadef84c8e868d81350bd8ac61): perf score=1.000000
I20260812 06:17:33.320839 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: MajorDeltaCompactionOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.134s	user 0.111s	sys 0.023s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":169,"lbm_read_time_us":10168,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25007,"lbm_writes_lt_1ms":443,"mutex_wait_us":37,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4096,"update_count":2000}
I20260812 06:17:33.321424 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61): perf score=10.126437
I20260812 06:17:33.366771 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.045s	user 0.018s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14505,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:33.367324 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61): perf score=2.188937
I20260812 06:17:33.378575 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4265,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:33.379334 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling FlushMRSOp(24c408aadef84c8e868d81350bd8ac61): perf score=1.000000
I20260812 06:17:33.410693 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: FlushMRSOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.031s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":85,"dirs.run_cpu_time_us":188,"dirs.run_wall_time_us":1408,"drs_written":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2098,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:17:33.411365 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling LogGCOp(24c408aadef84c8e868d81350bd8ac61): free 124710300 bytes of WAL
I20260812 06:17:33.411597 18041 log_reader.cc:385] T 24c408aadef84c8e868d81350bd8ac61: removed 12 log segments from log reader
I20260812 06:17:33.411680 18041 log.cc:1079] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/24c408aadef84c8e868d81350bd8ac61/wal-000000015 (ops 69-73)
I20260812 06:17:33.411741 18041 log.cc:1079] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/24c408aadef84c8e868d81350bd8ac61/wal-000000016 (ops 74-78)
I20260812 06:17:33.411801 18041 log.cc:1079] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/24c408aadef84c8e868d81350bd8ac61/wal-000000017 (ops 79-83)
I20260812 06:17:33.411847 18041 log.cc:1079] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/24c408aadef84c8e868d81350bd8ac61/wal-000000018 (ops 84-88)
I20260812 06:17:33.411887 18041 log.cc:1079] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/24c408aadef84c8e868d81350bd8ac61/wal-000000019 (ops 89-93)
I20260812 06:17:33.411926 18041 log.cc:1079] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/24c408aadef84c8e868d81350bd8ac61/wal-000000020 (ops 94-98)
I20260812 06:17:33.411963 18041 log.cc:1079] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/24c408aadef84c8e868d81350bd8ac61/wal-000000021 (ops 99-103)
I20260812 06:17:33.412000 18041 log.cc:1079] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/24c408aadef84c8e868d81350bd8ac61/wal-000000022 (ops 104-108)
I20260812 06:17:33.412037 18041 log.cc:1079] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/24c408aadef84c8e868d81350bd8ac61/wal-000000023 (ops 109-113)
I20260812 06:17:33.412076 18041 log.cc:1079] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/24c408aadef84c8e868d81350bd8ac61/wal-000000024 (ops 114-118)
I20260812 06:17:33.412113 18041 log.cc:1079] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/24c408aadef84c8e868d81350bd8ac61/wal-000000025 (ops 119-123)
I20260812 06:17:33.412151 18041 log.cc:1079] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/24c408aadef84c8e868d81350bd8ac61/wal-000000026 (ops 124-128)
I20260812 06:17:33.440661 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: LogGCOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.029s	user 0.006s	sys 0.022s Metrics: {}
I20260812 06:17:33.441107 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61): perf score=3.181125
I20260812 06:17:33.460379 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.019s	user 0.009s	sys 0.008s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":7259,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:33.460891 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61): perf score=2.188937
I20260812 06:17:33.470547 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3676,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:33.471220 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling MajorDeltaCompactionOp(24c408aadef84c8e868d81350bd8ac61): perf score=1.000000
I20260812 06:17:33.655815 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: MajorDeltaCompactionOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.184s	user 0.153s	sys 0.024s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877326,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":765,"lbm_read_time_us":13073,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34293,"lbm_writes_lt_1ms":643,"mutex_wait_us":25,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":21888,"thread_start_us":127,"threads_started":1,"update_count":3000}
I20260812 06:17:33.656607 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61): perf score=14.095187
I20260812 06:17:33.710810 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.054s	user 0.031s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":27943,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:33.711359 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling UndoDeltaBlockGCOp(24c408aadef84c8e868d81350bd8ac61): 472 bytes on disk
I20260812 06:17:33.711813 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: UndoDeltaBlockGCOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4}
I20260812 06:17:33.712311 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61): perf score=2.188937
I20260812 06:17:33.725571 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5406,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:33.726028 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling MajorDeltaCompactionOp(24c408aadef84c8e868d81350bd8ac61): perf score=1.000000
I20260812 06:17:33.876283 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: MajorDeltaCompactionOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.150s	user 0.119s	sys 0.028s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":161,"lbm_read_time_us":10640,"lbm_reads_lt_1ms":568,"lbm_write_time_us":28107,"lbm_writes_lt_1ms":543,"mutex_wait_us":39,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11392,"update_count":2500}
I20260812 06:17:33.876921 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61): perf score=11.118625
I20260812 06:17:33.931573 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.054s	user 0.022s	sys 0.016s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":18643,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:17:33.932191 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61): perf score=6.157687
I20260812 06:17:33.957777 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.025s	user 0.016s	sys 0.005s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":8984,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:17:33.958407 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling MajorDeltaCompactionOp(24c408aadef84c8e868d81350bd8ac61): perf score=1.000000
I20260812 06:17:34.118894 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: MajorDeltaCompactionOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.160s	user 0.116s	sys 0.032s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774693,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":281,"lbm_read_time_us":10228,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31235,"lbm_writes_lt_1ms":543,"mutex_wait_us":61,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":25600,"update_count":2500}
I20260812 06:17:34.119611 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61): perf score=14.095187
I20260812 06:17:34.173574 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.054s	user 0.018s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21705,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:34.174073 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61): perf score=2.188937
I20260812 06:17:34.186446 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4323,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:34.187160 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling MajorDeltaCompactionOp(24c408aadef84c8e868d81350bd8ac61): perf score=1.000000
I20260812 06:17:34.351282 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: MajorDeltaCompactionOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.164s	user 0.118s	sys 0.031s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":234,"lbm_read_time_us":10815,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30104,"lbm_writes_lt_1ms":543,"mutex_wait_us":47,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2500}
I20260812 06:17:34.351905 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61): perf score=14.095187
I20260812 06:17:34.407814 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.056s	user 0.045s	sys 0.004s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22206,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:34.408281 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61): perf score=2.188937
I20260812 06:17:34.418834 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4152,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:34.419343 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling MajorDeltaCompactionOp(24c408aadef84c8e868d81350bd8ac61): perf score=1.000000
I20260812 06:17:34.601603 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: MajorDeltaCompactionOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.182s	user 0.107s	sys 0.069s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":460,"lbm_read_time_us":12109,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29145,"lbm_writes_lt_1ms":543,"mutex_wait_us":28,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12544,"update_count":2500}
I20260812 06:17:34.602413 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61): perf score=14.095187
I20260812 06:17:34.674774 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.072s	user 0.031s	sys 0.028s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":26192,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:34.675254 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61): perf score=2.188937
I20260812 06:17:34.686185 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3932,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:34.686983 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling MajorDeltaCompactionOp(24c408aadef84c8e868d81350bd8ac61): perf score=1.000000
I20260812 06:17:34.891332 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: MajorDeltaCompactionOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.204s	user 0.136s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":777,"lbm_read_time_us":13302,"lbm_reads_lt_1ms":572,"lbm_write_time_us":37780,"lbm_writes_lt_1ms":543,"mutex_wait_us":316,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:34.892113 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61): perf score=14.095187
I20260812 06:17:34.948987 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.057s	user 0.034s	sys 0.008s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":18415,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:34.949704 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61): perf score=2.188937
I20260812 06:17:34.962137 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.012s	user 0.008s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4793,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:34.962710 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling FlushMRSOp(24c408aadef84c8e868d81350bd8ac61): perf score=1.000000
I20260812 06:17:34.996698 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: FlushMRSOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.034s	user 0.033s	sys 0.000s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":186,"dirs.run_wall_time_us":1283,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1665,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:17:34.997365 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling LogGCOp(24c408aadef84c8e868d81350bd8ac61): free 129773835 bytes of WAL
I20260812 06:17:34.997614 18041 log_reader.cc:385] T 24c408aadef84c8e868d81350bd8ac61: removed 13 log segments from log reader
I20260812 06:17:34.997658 18041 log.cc:1079] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/24c408aadef84c8e868d81350bd8ac61/wal-000000027 (ops 129-133)
I20260812 06:17:34.997689 18041 log.cc:1079] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/24c408aadef84c8e868d81350bd8ac61/wal-000000028 (ops 134-138)
I20260812 06:17:34.997740 18041 log.cc:1079] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/24c408aadef84c8e868d81350bd8ac61/wal-000000029 (ops 139-143)
I20260812 06:17:34.997784 18041 log.cc:1079] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/24c408aadef84c8e868d81350bd8ac61/wal-000000030 (ops 144-148)
I20260812 06:17:34.997826 18041 log.cc:1079] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/24c408aadef84c8e868d81350bd8ac61/wal-000000031 (ops 149-152)
I20260812 06:17:34.997874 18041 log.cc:1079] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/24c408aadef84c8e868d81350bd8ac61/wal-000000032 (ops 153-157)
I20260812 06:17:34.997905 18041 log.cc:1079] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/24c408aadef84c8e868d81350bd8ac61/wal-000000033 (ops 158-162)
I20260812 06:17:34.997969 18041 log.cc:1079] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/24c408aadef84c8e868d81350bd8ac61/wal-000000034 (ops 163-167)
I20260812 06:17:34.997996 18041 log.cc:1079] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/24c408aadef84c8e868d81350bd8ac61/wal-000000035 (ops 168-172)
I20260812 06:17:34.998035 18041 log.cc:1079] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/24c408aadef84c8e868d81350bd8ac61/wal-000000036 (ops 173-177)
I20260812 06:17:34.998065 18041 log.cc:1079] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/24c408aadef84c8e868d81350bd8ac61/wal-000000037 (ops 178-182)
I20260812 06:17:34.998099 18041 log.cc:1079] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/24c408aadef84c8e868d81350bd8ac61/wal-000000038 (ops 183-187)
I20260812 06:17:34.998127 18041 log.cc:1079] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/24c408aadef84c8e868d81350bd8ac61/wal-000000039 (ops 188-192)
I20260812 06:17:35.030117 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: LogGCOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.033s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:17:35.031601 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61): perf score=5.165500
I20260812 06:17:35.051194 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.019s	user 0.009s	sys 0.008s Metrics: {"bytes_written":6523086,"delete_count":0,"lbm_write_time_us":8125,"lbm_writes_lt_1ms":162,"reinsert_count":0,"update_count":795}
I20260812 06:17:35.051736 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling LogGCOp(24c408aadef84c8e868d81350bd8ac61): free 11564893 bytes of WAL
I20260812 06:17:35.051951 18041 log_reader.cc:385] T 24c408aadef84c8e868d81350bd8ac61: removed 1 log segments from log reader
I20260812 06:17:35.051996 18041 log.cc:1079] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6: Deleting log segment in path: /tmp/dist-test-taskmiwFOI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444658860-17588-0/minicluster-data/ts-0-root/wals/24c408aadef84c8e868d81350bd8ac61/wal-000000040 (ops 193-196)
I20260812 06:17:35.054252 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: LogGCOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:17:35.054653 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61): perf score=1.000000
I20260812 06:17:35.062528 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: FlushDeltaMemStoresOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.008s	user 0.006s	sys 0.000s Metrics: {"bytes_written":1682177,"delete_count":0,"lbm_write_time_us":2238,"lbm_writes_lt_1ms":44,"reinsert_count":0,"update_count":205}
I20260812 06:17:35.063055 18137 maintenance_manager.cc:419] P f96a0c86748f46d3b28b73289a242ff6: Scheduling MajorDeltaCompactionOp(24c408aadef84c8e868d81350bd8ac61): perf score=1.000000
I20260812 06:17:35.145287 17588 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.845s	user 1.823s	sys 0.142s
I20260812 06:17:35.238677 17588 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.093s	user 0.001s	sys 0.000s
I20260812 06:17:35.239267 17588 tablet_server.cc:179] TabletServer@127.17.45.1:0 shutting down...
I20260812 06:17:35.274614 18041 maintenance_manager.cc:643] P f96a0c86748f46d3b28b73289a242ff6: MajorDeltaCompactionOp(24c408aadef84c8e868d81350bd8ac61) complete. Timing: real 0.211s	user 0.147s	sys 0.064s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979689,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1250,"lbm_read_time_us":15394,"lbm_reads_lt_1ms":770,"lbm_write_time_us":32833,"lbm_writes_lt_1ms":743,"mutex_wait_us":138,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":46080,"thread_start_us":85,"threads_started":1,"update_count":3500}
I20260812 06:17:35.275703 17588 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:35.276021 17588 tablet_replica.cc:333] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6: stopping tablet replica
I20260812 06:17:35.276180 17588 raft_consensus.cc:2243] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:35.276362 17588 raft_consensus.cc:2272] T 24c408aadef84c8e868d81350bd8ac61 P f96a0c86748f46d3b28b73289a242ff6 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:35.281468 17588 tablet_server.cc:196] TabletServer@127.17.45.1:0 shutdown complete.
I20260812 06:17:35.333665 17588 master.cc:562] Master@127.17.45.62:37657 shutting down...
I20260812 06:17:35.336812 17588 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 8d575546660f4f1487d192884fe5cf42 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:35.336989 17588 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 8d575546660f4f1487d192884fe5cf42 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:35.337039 17588 tablet_replica.cc:333] T 00000000000000000000000000000000 P 8d575546660f4f1487d192884fe5cf42: stopping tablet replica
I20260812 06:17:35.349478 17588 master.cc:584] Master@127.17.45.62:37657 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5335 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10769 ms total)

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