[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:19:14.143324 18299 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.17.222.254:40039
I20260812 06:19:14.144434 18299 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:19:14.145124 18299 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:14.152560 18312 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:14.152776 18299 server_base.cc:1061] running on GCE node
W20260812 06:19:14.152602 18317 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:14.153055 18309 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:14.153679 18299 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:14.153826 18299 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:14.153874 18299 hybrid_clock.cc:648] HybridClock initialized: now 1786515554153870 us; error 0 us; skew 500 ppm
I20260812 06:19:14.155810 18299 webserver.cc:533] Webserver started at http://127.17.222.254:45721/ using document root <none> and password file <none>
I20260812 06:19:14.156409 18299 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:14.156513 18299 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:14.156787 18299 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:14.158572 18299 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554132257-18299-0/minicluster-data/master-0-root/instance:
uuid: "0f3757037d764c4d8edf71f65c1f3101"
format_stamp: "Formatted at 2026-08-12 06:19:14 on dist-test-slave-3h5h"
I20260812 06:19:14.162364 18299 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.005s	sys 0.000s
I20260812 06:19:14.164781 18323 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:14.165963 18299 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:19:14.166133 18299 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554132257-18299-0/minicluster-data/master-0-root
uuid: "0f3757037d764c4d8edf71f65c1f3101"
format_stamp: "Formatted at 2026-08-12 06:19:14 on dist-test-slave-3h5h"
I20260812 06:19:14.166256 18299 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554132257-18299-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554132257-18299-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554132257-18299-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:14.192881 18299 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:14.193681 18299 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:19:14.193923 18299 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:14.203115 18299 rpc_server.cc:307] RPC server started. Bound to: 127.17.222.254:40039
I20260812 06:19:14.203198 18400 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.17.222.254:40039 every 8 connection(s)
I20260812 06:19:14.205827 18401 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:14.211843 18401 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 0f3757037d764c4d8edf71f65c1f3101: Bootstrap starting.
I20260812 06:19:14.214529 18401 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 0f3757037d764c4d8edf71f65c1f3101: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:14.215476 18401 log.cc:826] T 00000000000000000000000000000000 P 0f3757037d764c4d8edf71f65c1f3101: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:14.217625 18401 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 0f3757037d764c4d8edf71f65c1f3101: No bootstrap required, opened a new log
I20260812 06:19:14.220682 18401 raft_consensus.cc:359] T 00000000000000000000000000000000 P 0f3757037d764c4d8edf71f65c1f3101 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0f3757037d764c4d8edf71f65c1f3101" member_type: VOTER }
I20260812 06:19:14.220949 18401 raft_consensus.cc:385] T 00000000000000000000000000000000 P 0f3757037d764c4d8edf71f65c1f3101 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:14.221016 18401 raft_consensus.cc:740] T 00000000000000000000000000000000 P 0f3757037d764c4d8edf71f65c1f3101 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 0f3757037d764c4d8edf71f65c1f3101, State: Initialized, Role: FOLLOWER
I20260812 06:19:14.221632 18401 consensus_queue.cc:260] T 00000000000000000000000000000000 P 0f3757037d764c4d8edf71f65c1f3101 [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: "0f3757037d764c4d8edf71f65c1f3101" member_type: VOTER }
I20260812 06:19:14.221781 18401 raft_consensus.cc:399] T 00000000000000000000000000000000 P 0f3757037d764c4d8edf71f65c1f3101 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:14.221823 18401 raft_consensus.cc:493] T 00000000000000000000000000000000 P 0f3757037d764c4d8edf71f65c1f3101 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:14.221920 18401 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 0f3757037d764c4d8edf71f65c1f3101 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:14.222769 18401 raft_consensus.cc:515] T 00000000000000000000000000000000 P 0f3757037d764c4d8edf71f65c1f3101 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0f3757037d764c4d8edf71f65c1f3101" member_type: VOTER }
I20260812 06:19:14.223207 18401 leader_election.cc:304] T 00000000000000000000000000000000 P 0f3757037d764c4d8edf71f65c1f3101 [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: 0f3757037d764c4d8edf71f65c1f3101; no voters: 
I20260812 06:19:14.223512 18401 leader_election.cc:290] T 00000000000000000000000000000000 P 0f3757037d764c4d8edf71f65c1f3101 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:14.223891 18404 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 0f3757037d764c4d8edf71f65c1f3101 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:14.224263 18404 raft_consensus.cc:697] T 00000000000000000000000000000000 P 0f3757037d764c4d8edf71f65c1f3101 [term 1 LEADER]: Becoming Leader. State: Replica: 0f3757037d764c4d8edf71f65c1f3101, State: Running, Role: LEADER
I20260812 06:19:14.224699 18401 sys_catalog.cc:565] T 00000000000000000000000000000000 P 0f3757037d764c4d8edf71f65c1f3101 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:14.224712 18404 consensus_queue.cc:237] T 00000000000000000000000000000000 P 0f3757037d764c4d8edf71f65c1f3101 [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: "0f3757037d764c4d8edf71f65c1f3101" member_type: VOTER }
I20260812 06:19:14.227126 18299 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:14.227126 18406 sys_catalog.cc:455] T 00000000000000000000000000000000 P 0f3757037d764c4d8edf71f65c1f3101 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 0f3757037d764c4d8edf71f65c1f3101. Latest consensus state: current_term: 1 leader_uuid: "0f3757037d764c4d8edf71f65c1f3101" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0f3757037d764c4d8edf71f65c1f3101" member_type: VOTER } }
I20260812 06:19:14.227259 18406 sys_catalog.cc:458] T 00000000000000000000000000000000 P 0f3757037d764c4d8edf71f65c1f3101 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:14.227185 18405 sys_catalog.cc:455] T 00000000000000000000000000000000 P 0f3757037d764c4d8edf71f65c1f3101 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "0f3757037d764c4d8edf71f65c1f3101" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0f3757037d764c4d8edf71f65c1f3101" member_type: VOTER } }
I20260812 06:19:14.227320 18405 sys_catalog.cc:458] T 00000000000000000000000000000000 P 0f3757037d764c4d8edf71f65c1f3101 [sys.catalog]: This master's current role is: LEADER
W20260812 06:19:14.229684 18424 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 0f3757037d764c4d8edf71f65c1f3101: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:19:14.229770 18424 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:19:14.229869 18425 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:14.230715 18425 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:14.235693 18425 catalog_manager.cc:1383] Generated new cluster ID: 7ab13decd51e4230bef337c5e9f2973a
I20260812 06:19:14.235777 18425 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:14.244248 18425 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:14.245529 18425 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:14.256862 18425 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 0f3757037d764c4d8edf71f65c1f3101: Generated new TSK 0
I20260812 06:19:14.257712 18425 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:14.259950 18299 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:14.263262 18430 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:14.263310 18431 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:14.263561 18433 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:14.263744 18299 server_base.cc:1061] running on GCE node
I20260812 06:19:14.263942 18299 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:14.263993 18299 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:14.264014 18299 hybrid_clock.cc:648] HybridClock initialized: now 1786515554264014 us; error 0 us; skew 500 ppm
I20260812 06:19:14.265069 18299 webserver.cc:533] Webserver started at http://127.17.222.193:32847/ using document root <none> and password file <none>
I20260812 06:19:14.265255 18299 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:14.265316 18299 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:14.265388 18299 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:14.265832 18299 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554132257-18299-0/minicluster-data/ts-0-root/instance:
uuid: "fcf60faa79134febb0f023f64d789867"
format_stamp: "Formatted at 2026-08-12 06:19:14 on dist-test-slave-3h5h"
I20260812 06:19:14.267802 18299 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:14.269088 18442 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:14.269402 18299 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:14.269486 18299 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554132257-18299-0/minicluster-data/ts-0-root
uuid: "fcf60faa79134febb0f023f64d789867"
format_stamp: "Formatted at 2026-08-12 06:19:14 on dist-test-slave-3h5h"
I20260812 06:19:14.269596 18299 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554132257-18299-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554132257-18299-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554132257-18299-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:14.283706 18299 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:14.284261 18299 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:14.285290 18299 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:14.286255 18299 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:14.286312 18299 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:14.286391 18299 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:14.286438 18299 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:14.294111 18299 rpc_server.cc:307] RPC server started. Bound to: 127.17.222.193:34959
I20260812 06:19:14.294157 18544 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.17.222.193:34959 every 8 connection(s)
I20260812 06:19:14.308477 18545 heartbeater.cc:344] Connected to a master server at 127.17.222.254:40039
I20260812 06:19:14.308761 18545 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:14.309350 18545 heartbeater.cc:507] Master 127.17.222.254:40039 requested a full tablet report, sending...
I20260812 06:19:14.311302 18347 ts_manager.cc:194] Registered new tserver with Master: fcf60faa79134febb0f023f64d789867 (127.17.222.193:34959)
I20260812 06:19:14.311802 18299 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.016934296s
I20260812 06:19:14.312883 18347 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:37664
I20260812 06:19:14.321830 18347 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:37678:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:14.337814 18484 tablet_service.cc:1511] Processing CreateTablet for tablet cd952c0abb8a4d1c85165b15b2654768 (DEFAULT_TABLE table=heavy-update-compaction-test [id=69ef650619e941a085d33a38bbe9ec62]), partition=
I20260812 06:19:14.338335 18484 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet cd952c0abb8a4d1c85165b15b2654768. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:14.341179 18564 tablet_bootstrap.cc:492] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867: Bootstrap starting.
I20260812 06:19:14.342170 18564 tablet_bootstrap.cc:654] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:14.343528 18564 tablet_bootstrap.cc:492] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867: No bootstrap required, opened a new log
I20260812 06:19:14.343647 18564 ts_tablet_manager.cc:1403] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:19:14.344152 18564 raft_consensus.cc:359] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fcf60faa79134febb0f023f64d789867" member_type: VOTER last_known_addr { host: "127.17.222.193" port: 34959 } }
I20260812 06:19:14.344264 18564 raft_consensus.cc:385] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:14.344290 18564 raft_consensus.cc:740] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: fcf60faa79134febb0f023f64d789867, State: Initialized, Role: FOLLOWER
I20260812 06:19:14.344482 18564 consensus_queue.cc:260] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867 [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: "fcf60faa79134febb0f023f64d789867" member_type: VOTER last_known_addr { host: "127.17.222.193" port: 34959 } }
I20260812 06:19:14.344596 18564 raft_consensus.cc:399] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:14.344666 18564 raft_consensus.cc:493] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:14.344725 18564 raft_consensus.cc:3060] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:14.345552 18564 raft_consensus.cc:515] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fcf60faa79134febb0f023f64d789867" member_type: VOTER last_known_addr { host: "127.17.222.193" port: 34959 } }
I20260812 06:19:14.345726 18564 leader_election.cc:304] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867 [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: fcf60faa79134febb0f023f64d789867; no voters: 
I20260812 06:19:14.346029 18564 leader_election.cc:290] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:14.346139 18566 raft_consensus.cc:2804] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:14.346354 18566 raft_consensus.cc:697] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867 [term 1 LEADER]: Becoming Leader. State: Replica: fcf60faa79134febb0f023f64d789867, State: Running, Role: LEADER
I20260812 06:19:14.346468 18564 ts_tablet_manager.cc:1434] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:19:14.346637 18566 consensus_queue.cc:237] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867 [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: "fcf60faa79134febb0f023f64d789867" member_type: VOTER last_known_addr { host: "127.17.222.193" port: 34959 } }
I20260812 06:19:14.346794 18545 heartbeater.cc:499] Master 127.17.222.254:40039 was elected leader, sending a full tablet report...
I20260812 06:19:14.349913 18345 catalog_manager.cc:5719] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867 reported cstate change: term changed from 0 to 1, leader changed from <none> to fcf60faa79134febb0f023f64d789867 (127.17.222.193). New cstate: current_term: 1 leader_uuid: "fcf60faa79134febb0f023f64d789867" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fcf60faa79134febb0f023f64d789867" member_type: VOTER last_known_addr { host: "127.17.222.193" port: 34959 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:14.421941 18299 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.065s	user 0.020s	sys 0.012s
I20260812 06:19:14.545344 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling FlushMRSOp(cd952c0abb8a4d1c85165b15b2654768): perf score=15.086190
I20260812 06:19:14.671269 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: FlushMRSOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.126s	user 0.090s	sys 0.033s Metrics: {"bytes_written":9230684,"cfile_init":1,"compiler_manager_pool.queue_time_us":263,"delete_count":0,"dirs.queue_time_us":58,"dirs.run_cpu_time_us":225,"dirs.run_wall_time_us":1006,"drs_written":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4,"lbm_write_time_us":30054,"lbm_writes_lt_1ms":582,"mutex_wait_us":345,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"spinlock_wait_cycles":139648,"thread_start_us":152,"threads_started":1,"update_count":1125}
I20260812 06:19:14.672320 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling LogGCOp(cd952c0abb8a4d1c85165b15b2654768): free 11976772 bytes of WAL
I20260812 06:19:14.672617 18448 log_reader.cc:385] T cd952c0abb8a4d1c85165b15b2654768: removed 1 log segments from log reader
I20260812 06:19:14.672694 18448 log.cc:1079] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/cd952c0abb8a4d1c85165b15b2654768/wal-000000001 (ops 1-6)
I20260812 06:19:14.675209 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: LogGCOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:19:14.675523 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768): perf score=1.196750
I20260812 06:19:14.690124 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.014s	user 0.008s	sys 0.003s Metrics: {"bytes_written":3077030,"delete_count":0,"lbm_write_time_us":4741,"lbm_writes_lt_1ms":78,"reinsert_count":0,"update_count":375}
I20260812 06:19:14.690621 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling MajorDeltaCompactionOp(cd952c0abb8a4d1c85165b15b2654768): perf score=1.000000
I20260812 06:19:14.818125 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: MajorDeltaCompactionOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.127s	user 0.107s	sys 0.019s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16528877,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":855,"lbm_read_time_us":8328,"lbm_reads_lt_1ms":368,"lbm_write_time_us":23599,"lbm_writes_lt_1ms":343,"mutex_wait_us":22,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":3328,"thread_start_us":354,"threads_started":5,"update_count":1500}
I20260812 06:19:14.818856 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768): perf score=10.126437
I20260812 06:19:14.859702 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.041s	user 0.022s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19654,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:14.860170 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768): perf score=2.188937
I20260812 06:19:14.873059 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.013s	user 0.000s	sys 0.012s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4083,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:14.873579 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling UndoDeltaBlockGCOp(cd952c0abb8a4d1c85165b15b2654768): 12308959 bytes on disk
I20260812 06:19:14.874253 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: UndoDeltaBlockGCOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":98,"lbm_reads_lt_1ms":4}
I20260812 06:19:14.874941 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling MajorDeltaCompactionOp(cd952c0abb8a4d1c85165b15b2654768): perf score=1.000000
I20260812 06:19:15.013756 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: MajorDeltaCompactionOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.139s	user 0.120s	sys 0.018s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":880,"lbm_read_time_us":8066,"lbm_reads_lt_1ms":464,"lbm_write_time_us":30702,"lbm_writes_lt_1ms":443,"mutex_wait_us":4,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":22912,"update_count":2000}
I20260812 06:19:15.014510 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768): perf score=10.126437
I20260812 06:19:15.068288 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.054s	user 0.019s	sys 0.031s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":21866,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:19:15.069154 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768): perf score=2.188937
I20260812 06:19:15.089003 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.020s	user 0.011s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7640,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:15.089598 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling MajorDeltaCompactionOp(cd952c0abb8a4d1c85165b15b2654768): perf score=1.000000
I20260812 06:19:15.235136 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: MajorDeltaCompactionOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.145s	user 0.106s	sys 0.039s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":330,"lbm_read_time_us":10149,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25296,"lbm_writes_lt_1ms":443,"mutex_wait_us":41,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10112,"update_count":2000}
I20260812 06:19:15.235756 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768): perf score=10.126437
I20260812 06:19:15.278769 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.043s	user 0.020s	sys 0.014s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15829,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:15.279265 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768): perf score=2.188937
I20260812 06:19:15.290436 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4041,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:15.291034 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling MajorDeltaCompactionOp(cd952c0abb8a4d1c85165b15b2654768): perf score=1.000000
I20260812 06:19:15.427320 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: MajorDeltaCompactionOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.136s	user 0.111s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":168,"lbm_read_time_us":10333,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26039,"lbm_writes_lt_1ms":443,"mutex_wait_us":44,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10368,"update_count":2000}
I20260812 06:19:15.427922 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768): perf score=10.126437
I20260812 06:19:15.465701 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.038s	user 0.019s	sys 0.015s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":14749,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:15.466317 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling MajorDeltaCompactionOp(cd952c0abb8a4d1c85165b15b2654768): perf score=1.000000
I20260812 06:19:15.569002 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: MajorDeltaCompactionOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.102s	user 0.097s	sys 0.004s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16528784,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1321,"lbm_read_time_us":6025,"lbm_reads_lt_1ms":363,"lbm_write_time_us":18612,"lbm_writes_lt_1ms":343,"mutex_wait_us":995,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":13824,"update_count":1500}
I20260812 06:19:15.569672 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768): perf score=10.126437
I20260812 06:19:15.607808 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.038s	user 0.019s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16508,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:15.608325 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768): perf score=2.188937
I20260812 06:19:15.620042 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4003,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:15.620484 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling MajorDeltaCompactionOp(cd952c0abb8a4d1c85165b15b2654768): perf score=1.000000
I20260812 06:19:15.758351 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: MajorDeltaCompactionOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.138s	user 0.089s	sys 0.043s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":760,"lbm_read_time_us":8097,"lbm_reads_lt_1ms":468,"lbm_write_time_us":24950,"lbm_writes_lt_1ms":443,"mutex_wait_us":399,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14720,"update_count":2000}
I20260812 06:19:15.759279 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768): perf score=10.126437
I20260812 06:19:15.794682 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.035s	user 0.021s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15443,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:15.795257 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768): perf score=2.188937
I20260812 06:19:15.811391 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.016s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6092,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:15.811988 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling MajorDeltaCompactionOp(cd952c0abb8a4d1c85165b15b2654768): perf score=1.000000
I20260812 06:19:15.943640 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: MajorDeltaCompactionOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.131s	user 0.100s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1068,"lbm_read_time_us":9672,"lbm_reads_lt_1ms":468,"lbm_write_time_us":23439,"lbm_writes_lt_1ms":443,"mutex_wait_us":106,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3456,"update_count":2000}
I20260812 06:19:15.944169 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768): perf score=10.126437
I20260812 06:19:15.992432 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.048s	user 0.029s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":23850,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:19:15.993129 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768): perf score=2.188937
I20260812 06:19:16.009568 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.016s	user 0.015s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6335,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:16.010241 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling FlushMRSOp(cd952c0abb8a4d1c85165b15b2654768): perf score=1.000000
I20260812 06:19:16.046401 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: FlushMRSOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.036s	user 0.029s	sys 0.004s Metrics: {"bytes_written":1275444,"cfile_init":1,"dirs.queue_time_us":73,"dirs.run_cpu_time_us":393,"dirs.run_wall_time_us":1720,"drs_written":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1821,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:16.047353 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling LogGCOp(cd952c0abb8a4d1c85165b15b2654768): free 129320491 bytes of WAL
I20260812 06:19:16.047653 18448 log_reader.cc:385] T cd952c0abb8a4d1c85165b15b2654768: removed 13 log segments from log reader
I20260812 06:19:16.047705 18448 log.cc:1079] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/cd952c0abb8a4d1c85165b15b2654768/wal-000000002 (ops 7-11)
I20260812 06:19:16.047739 18448 log.cc:1079] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/cd952c0abb8a4d1c85165b15b2654768/wal-000000003 (ops 12-16)
I20260812 06:19:16.047758 18448 log.cc:1079] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/cd952c0abb8a4d1c85165b15b2654768/wal-000000004 (ops 17-21)
I20260812 06:19:16.047823 18448 log.cc:1079] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/cd952c0abb8a4d1c85165b15b2654768/wal-000000005 (ops 22-26)
I20260812 06:19:16.047873 18448 log.cc:1079] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/cd952c0abb8a4d1c85165b15b2654768/wal-000000006 (ops 27-30)
I20260812 06:19:16.047923 18448 log.cc:1079] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/cd952c0abb8a4d1c85165b15b2654768/wal-000000007 (ops 31-35)
I20260812 06:19:16.047984 18448 log.cc:1079] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/cd952c0abb8a4d1c85165b15b2654768/wal-000000008 (ops 36-40)
I20260812 06:19:16.048030 18448 log.cc:1079] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/cd952c0abb8a4d1c85165b15b2654768/wal-000000009 (ops 41-45)
I20260812 06:19:16.048092 18448 log.cc:1079] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/cd952c0abb8a4d1c85165b15b2654768/wal-000000010 (ops 46-50)
I20260812 06:19:16.048135 18448 log.cc:1079] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/cd952c0abb8a4d1c85165b15b2654768/wal-000000011 (ops 51-55)
I20260812 06:19:16.048177 18448 log.cc:1079] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/cd952c0abb8a4d1c85165b15b2654768/wal-000000012 (ops 56-60)
I20260812 06:19:16.048203 18448 log.cc:1079] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/cd952c0abb8a4d1c85165b15b2654768/wal-000000013 (ops 61-64)
I20260812 06:19:16.048245 18448 log.cc:1079] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/cd952c0abb8a4d1c85165b15b2654768/wal-000000014 (ops 65-69)
I20260812 06:19:16.081036 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: LogGCOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.033s	user 0.000s	sys 0.033s Metrics: {}
I20260812 06:19:16.081486 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768): perf score=5.165500
I20260812 06:19:16.102627 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.021s	user 0.010s	sys 0.009s Metrics: {"bytes_written":6892306,"delete_count":0,"lbm_write_time_us":7846,"lbm_writes_lt_1ms":171,"reinsert_count":0,"update_count":840}
I20260812 06:19:16.103171 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768): perf score=1.000000
I20260812 06:19:16.114895 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.012s	user 0.004s	sys 0.003s Metrics: {"bytes_written":1312952,"delete_count":0,"lbm_write_time_us":2544,"lbm_writes_lt_1ms":35,"reinsert_count":0,"update_count":160}
I20260812 06:19:16.115420 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling UndoDeltaBlockGCOp(cd952c0abb8a4d1c85165b15b2654768): 482 bytes on disk
I20260812 06:19:16.115859 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: UndoDeltaBlockGCOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4}
I20260812 06:19:16.116357 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling MajorDeltaCompactionOp(cd952c0abb8a4d1c85165b15b2654768): perf score=1.000000
I20260812 06:19:16.282495 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: MajorDeltaCompactionOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.166s	user 0.112s	sys 0.054s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836309,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":907,"lbm_read_time_us":11506,"lbm_reads_lt_1ms":666,"lbm_write_time_us":33618,"lbm_writes_lt_1ms":643,"mutex_wait_us":255,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":9216,"thread_start_us":82,"threads_started":1,"update_count":3000}
I20260812 06:19:16.283247 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768): perf score=14.095187
I20260812 06:19:16.347137 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.064s	user 0.047s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":28037,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:16.348053 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768): perf score=2.188937
I20260812 06:19:16.362843 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5681,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:16.363315 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling MajorDeltaCompactionOp(cd952c0abb8a4d1c85165b15b2654768): perf score=1.000000
I20260812 06:19:16.541909 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: MajorDeltaCompactionOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.178s	user 0.130s	sys 0.039s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1439,"lbm_read_time_us":10223,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34245,"lbm_writes_lt_1ms":543,"mutex_wait_us":363,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11008,"update_count":2500}
I20260812 06:19:16.542558 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768): perf score=14.095187
I20260812 06:19:16.586695 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.044s	user 0.028s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18208,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:16.587357 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling MajorDeltaCompactionOp(cd952c0abb8a4d1c85165b15b2654768): perf score=1.000000
I20260812 06:19:16.729800 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: MajorDeltaCompactionOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.142s	user 0.094s	sys 0.048s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20631193,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":246,"lbm_read_time_us":9181,"lbm_reads_lt_1ms":467,"lbm_write_time_us":26665,"lbm_writes_lt_1ms":443,"mutex_wait_us":107,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:16.730716 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768): perf score=10.126437
I20260812 06:19:16.769625 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.039s	user 0.023s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15361,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:16.770157 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768): perf score=2.188937
I20260812 06:19:16.786087 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.016s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6282,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:16.786736 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling MajorDeltaCompactionOp(cd952c0abb8a4d1c85165b15b2654768): perf score=1.000000
I20260812 06:19:16.916823 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: MajorDeltaCompactionOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.130s	user 0.100s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1299,"lbm_read_time_us":8021,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25478,"lbm_writes_lt_1ms":443,"mutex_wait_us":36,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5120,"update_count":2000}
I20260812 06:19:16.917487 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768): perf score=10.126437
I20260812 06:19:16.964600 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.047s	user 0.025s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15331,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:16.965159 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768): perf score=2.188937
I20260812 06:19:16.976982 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.012s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4431,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:16.977655 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling MajorDeltaCompactionOp(cd952c0abb8a4d1c85165b15b2654768): perf score=1.000000
I20260812 06:19:17.105196 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: MajorDeltaCompactionOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.127s	user 0.103s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":159,"lbm_read_time_us":8178,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25591,"lbm_writes_lt_1ms":443,"mutex_wait_us":34,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10496,"update_count":2000}
I20260812 06:19:17.105906 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768): perf score=10.126437
I20260812 06:19:17.157639 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.052s	user 0.035s	sys 0.008s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":19019,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:17.158223 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768): perf score=2.188937
I20260812 06:19:17.171433 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.013s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4910,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:17.172008 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling MajorDeltaCompactionOp(cd952c0abb8a4d1c85165b15b2654768): perf score=1.000000
I20260812 06:19:17.306344 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: MajorDeltaCompactionOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.134s	user 0.106s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":495,"lbm_read_time_us":10592,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25680,"lbm_writes_lt_1ms":443,"mutex_wait_us":364,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7680,"update_count":2000}
I20260812 06:19:17.306849 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768): perf score=10.126437
I20260812 06:19:17.367357 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.060s	user 0.031s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17330,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:17.367945 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768): perf score=2.188937
I20260812 06:19:17.384809 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.017s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6391,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:17.385694 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling MajorDeltaCompactionOp(cd952c0abb8a4d1c85165b15b2654768): perf score=1.000000
I20260812 06:19:17.532215 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: MajorDeltaCompactionOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.146s	user 0.097s	sys 0.049s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":244,"lbm_read_time_us":11314,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22945,"lbm_writes_lt_1ms":443,"mutex_wait_us":37,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8960,"update_count":2000}
I20260812 06:19:17.533011 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768): perf score=10.126437
I20260812 06:19:17.580631 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.047s	user 0.018s	sys 0.013s Metrics: {"bytes_written":12307494,"delete_count":0,"lbm_write_time_us":14655,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:17.581212 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768): perf score=2.188937
I20260812 06:19:17.591812 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.010s	user 0.000s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4123,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:17.592432 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling FlushMRSOp(cd952c0abb8a4d1c85165b15b2654768): perf score=1.000000
I20260812 06:19:17.624416 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: FlushMRSOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.032s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":75,"dirs.run_cpu_time_us":209,"dirs.run_wall_time_us":1477,"drs_written":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1742,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:17.625284 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling LogGCOp(cd952c0abb8a4d1c85165b15b2654768): free 124257255 bytes of WAL
I20260812 06:19:17.625530 18448 log_reader.cc:385] T cd952c0abb8a4d1c85165b15b2654768: removed 12 log segments from log reader
I20260812 06:19:17.625581 18448 log.cc:1079] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/cd952c0abb8a4d1c85165b15b2654768/wal-000000015 (ops 70-74)
I20260812 06:19:17.625639 18448 log.cc:1079] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/cd952c0abb8a4d1c85165b15b2654768/wal-000000016 (ops 75-79)
I20260812 06:19:17.625687 18448 log.cc:1079] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/cd952c0abb8a4d1c85165b15b2654768/wal-000000017 (ops 80-84)
I20260812 06:19:17.625758 18448 log.cc:1079] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/cd952c0abb8a4d1c85165b15b2654768/wal-000000018 (ops 85-89)
I20260812 06:19:17.625802 18448 log.cc:1079] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/cd952c0abb8a4d1c85165b15b2654768/wal-000000019 (ops 90-94)
I20260812 06:19:17.625849 18448 log.cc:1079] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/cd952c0abb8a4d1c85165b15b2654768/wal-000000020 (ops 95-99)
I20260812 06:19:17.625893 18448 log.cc:1079] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/cd952c0abb8a4d1c85165b15b2654768/wal-000000021 (ops 100-104)
I20260812 06:19:17.625937 18448 log.cc:1079] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/cd952c0abb8a4d1c85165b15b2654768/wal-000000022 (ops 105-109)
I20260812 06:19:17.625991 18448 log.cc:1079] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/cd952c0abb8a4d1c85165b15b2654768/wal-000000023 (ops 110-114)
I20260812 06:19:17.626035 18448 log.cc:1079] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/cd952c0abb8a4d1c85165b15b2654768/wal-000000024 (ops 115-118)
I20260812 06:19:17.626078 18448 log.cc:1079] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/cd952c0abb8a4d1c85165b15b2654768/wal-000000025 (ops 119-123)
I20260812 06:19:17.626123 18448 log.cc:1079] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/cd952c0abb8a4d1c85165b15b2654768/wal-000000026 (ops 124-128)
I20260812 06:19:17.652936 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: LogGCOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.027s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:19:17.653450 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768): perf score=3.181125
I20260812 06:19:17.674499 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.021s	user 0.011s	sys 0.008s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":4987,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:17.675086 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768): perf score=2.188937
I20260812 06:19:17.686193 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4095,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:17.686736 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling UndoDeltaBlockGCOp(cd952c0abb8a4d1c85165b15b2654768): 473 bytes on disk
I20260812 06:19:17.687215 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: UndoDeltaBlockGCOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4}
I20260812 06:19:17.687754 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling MajorDeltaCompactionOp(cd952c0abb8a4d1c85165b15b2654768): perf score=1.000000
I20260812 06:19:17.891028 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: MajorDeltaCompactionOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.203s	user 0.127s	sys 0.076s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836363,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":229,"lbm_read_time_us":15591,"lbm_reads_lt_1ms":674,"lbm_write_time_us":35475,"lbm_writes_lt_1ms":643,"mutex_wait_us":22,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3328,"thread_start_us":83,"threads_started":1,"update_count":3000}
I20260812 06:19:17.893674 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768): perf score=14.095187
I20260812 06:19:17.947588 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.054s	user 0.019s	sys 0.031s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":18848,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:17.948251 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768): perf score=2.188937
I20260812 06:19:17.963843 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6030,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:17.964376 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling MajorDeltaCompactionOp(cd952c0abb8a4d1c85165b15b2654768): perf score=1.000000
I20260812 06:19:18.146013 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: MajorDeltaCompactionOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.181s	user 0.094s	sys 0.075s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733726,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":240,"lbm_read_time_us":11292,"lbm_reads_lt_1ms":568,"lbm_write_time_us":27430,"lbm_writes_lt_1ms":543,"mutex_wait_us":32,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":30592,"update_count":2500}
I20260812 06:19:18.146663 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768): perf score=14.095187
I20260812 06:19:18.203828 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.057s	user 0.026s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23072,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:18.204411 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768): perf score=2.188937
I20260812 06:19:18.226315 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.022s	user 0.007s	sys 0.013s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4704,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:18.227108 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling MajorDeltaCompactionOp(cd952c0abb8a4d1c85165b15b2654768): perf score=1.000000
I20260812 06:19:18.389365 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: MajorDeltaCompactionOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.162s	user 0.107s	sys 0.055s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":814,"lbm_read_time_us":12238,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27847,"lbm_writes_lt_1ms":543,"mutex_wait_us":289,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7424,"update_count":2500}
I20260812 06:19:18.389891 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768): perf score=10.126437
I20260812 06:19:18.424621 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.035s	user 0.017s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14952,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:18.425292 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768): perf score=2.188937
I20260812 06:19:18.444653 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.019s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7151,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:18.445381 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling MajorDeltaCompactionOp(cd952c0abb8a4d1c85165b15b2654768): perf score=1.000000
I20260812 06:19:18.565376 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: MajorDeltaCompactionOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.120s	user 0.090s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":888,"lbm_read_time_us":7927,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24274,"lbm_writes_lt_1ms":443,"mutex_wait_us":265,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8064,"update_count":2000}
I20260812 06:19:18.566072 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768): perf score=10.126437
I20260812 06:19:18.604173 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.038s	user 0.022s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16272,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:18.604682 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768): perf score=2.188937
I20260812 06:19:18.616063 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4117,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:18.616549 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling MajorDeltaCompactionOp(cd952c0abb8a4d1c85165b15b2654768): perf score=1.000000
I20260812 06:19:18.735688 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: MajorDeltaCompactionOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.119s	user 0.090s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":264,"lbm_read_time_us":8020,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22349,"lbm_writes_lt_1ms":443,"mutex_wait_us":40,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14336,"update_count":2000}
I20260812 06:19:18.736513 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768): perf score=10.126437
I20260812 06:19:18.779692 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.043s	user 0.028s	sys 0.012s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":19221,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:18.780221 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768): perf score=2.188937
I20260812 06:19:18.792177 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4633,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:18.792655 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling MajorDeltaCompactionOp(cd952c0abb8a4d1c85165b15b2654768): perf score=1.000000
I20260812 06:19:18.941022 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: MajorDeltaCompactionOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.148s	user 0.114s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631314,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":2722,"lbm_read_time_us":7755,"lbm_reads_lt_1ms":472,"lbm_write_time_us":30217,"lbm_writes_lt_1ms":443,"mutex_wait_us":2210,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4096,"update_count":2000}
I20260812 06:19:18.941758 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768): perf score=11.118625
I20260812 06:19:18.996817 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.055s	user 0.014s	sys 0.035s Metrics: {"bytes_written":12717732,"delete_count":0,"lbm_write_time_us":22253,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:19:18.997546 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768): perf score=2.188937
I20260812 06:19:19.015394 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.018s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4798,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:19.015882 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768): perf score=2.188937
I20260812 06:19:19.026440 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4001,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:19.026954 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling FlushMRSOp(cd952c0abb8a4d1c85165b15b2654768): perf score=1.000000
I20260812 06:19:19.062220 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: FlushMRSOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.035s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1193507,"cfile_init":1,"dirs.queue_time_us":82,"dirs.run_cpu_time_us":254,"dirs.run_wall_time_us":1662,"drs_written":1,"lbm_read_time_us":96,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1367,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:19.062940 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling LogGCOp(cd952c0abb8a4d1c85165b15b2654768): free 124710562 bytes of WAL
I20260812 06:19:19.063275 18448 log_reader.cc:385] T cd952c0abb8a4d1c85165b15b2654768: removed 12 log segments from log reader
I20260812 06:19:19.063354 18448 log.cc:1079] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/cd952c0abb8a4d1c85165b15b2654768/wal-000000027 (ops 129-133)
I20260812 06:19:19.063406 18448 log.cc:1079] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/cd952c0abb8a4d1c85165b15b2654768/wal-000000028 (ops 134-138)
I20260812 06:19:19.063467 18448 log.cc:1079] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/cd952c0abb8a4d1c85165b15b2654768/wal-000000029 (ops 139-143)
I20260812 06:19:19.063509 18448 log.cc:1079] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/cd952c0abb8a4d1c85165b15b2654768/wal-000000030 (ops 144-148)
I20260812 06:19:19.063545 18448 log.cc:1079] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/cd952c0abb8a4d1c85165b15b2654768/wal-000000031 (ops 149-153)
I20260812 06:19:19.063592 18448 log.cc:1079] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/cd952c0abb8a4d1c85165b15b2654768/wal-000000032 (ops 154-158)
I20260812 06:19:19.063652 18448 log.cc:1079] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/cd952c0abb8a4d1c85165b15b2654768/wal-000000033 (ops 159-163)
I20260812 06:19:19.063688 18448 log.cc:1079] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/cd952c0abb8a4d1c85165b15b2654768/wal-000000034 (ops 164-168)
I20260812 06:19:19.063724 18448 log.cc:1079] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/cd952c0abb8a4d1c85165b15b2654768/wal-000000035 (ops 169-173)
I20260812 06:19:19.063766 18448 log.cc:1079] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/cd952c0abb8a4d1c85165b15b2654768/wal-000000036 (ops 174-178)
I20260812 06:19:19.063804 18448 log.cc:1079] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/cd952c0abb8a4d1c85165b15b2654768/wal-000000037 (ops 179-183)
I20260812 06:19:19.063843 18448 log.cc:1079] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/cd952c0abb8a4d1c85165b15b2654768/wal-000000038 (ops 184-188)
I20260812 06:19:19.090839 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: LogGCOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.028s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:19.091449 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768): perf score=3.181125
I20260812 06:19:19.107208 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.016s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4889,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:19.107684 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768): perf score=2.188937
I20260812 06:19:19.118160 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3810,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:19.118657 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling MajorDeltaCompactionOp(cd952c0abb8a4d1c85165b15b2654768): perf score=1.000000
I20260812 06:19:19.327075 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: MajorDeltaCompactionOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.208s	user 0.140s	sys 0.068s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32938880,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":502,"lbm_read_time_us":14346,"lbm_reads_lt_1ms":775,"lbm_write_time_us":39845,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":101,"threads_started":1,"update_count":3500}
I20260812 06:19:19.327997 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768): perf score=14.095187
I20260812 06:19:19.359632 18299 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.938s	user 1.882s	sys 0.117s
I20260812 06:19:19.387492 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.059s	user 0.031s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":27028,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":400,"reinsert_count":0,"update_count":2000}
I20260812 06:19:19.388036 18549 maintenance_manager.cc:419] P fcf60faa79134febb0f023f64d789867: Scheduling FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768): perf score=2.188937
I20260812 06:19:19.393887 18299 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.033s	user 0.005s	sys 0.000s
I20260812 06:19:19.394680 18299 tablet_server.cc:179] TabletServer@127.17.222.193:0 shutting down...
I20260812 06:19:19.403195 18448 maintenance_manager.cc:643] P fcf60faa79134febb0f023f64d789867: FlushDeltaMemStoresOp(cd952c0abb8a4d1c85165b15b2654768) complete. Timing: real 0.015s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6079,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:19.403762 18299 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:19.404193 18299 tablet_replica.cc:333] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867: stopping tablet replica
I20260812 06:19:19.404387 18299 raft_consensus.cc:2243] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:19.404565 18299 raft_consensus.cc:2272] T cd952c0abb8a4d1c85165b15b2654768 P fcf60faa79134febb0f023f64d789867 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:19.419497 18299 tablet_server.cc:196] TabletServer@127.17.222.193:0 shutdown complete.
I20260812 06:19:19.424556 18299 master.cc:562] Master@127.17.222.254:40039 shutting down...
I20260812 06:19:19.429045 18299 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 0f3757037d764c4d8edf71f65c1f3101 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:19.429275 18299 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 0f3757037d764c4d8edf71f65c1f3101 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:19.429384 18299 tablet_replica.cc:333] T 00000000000000000000000000000000 P 0f3757037d764c4d8edf71f65c1f3101: stopping tablet replica
I20260812 06:19:19.442255 18299 master.cc:584] Master@127.17.222.254:40039 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5387 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:19.530495 18299 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.17.222.254:42323
I20260812 06:19:19.530901 18299 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:19.533246 18594 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:19.533337 18589 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:19.533368 18299 server_base.cc:1061] running on GCE node
W20260812 06:19:19.533248 18588 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:19.533727 18299 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:19.533772 18299 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:19.533788 18299 hybrid_clock.cc:648] HybridClock initialized: now 1786515559533788 us; error 0 us; skew 500 ppm
I20260812 06:19:19.534596 18299 webserver.cc:533] Webserver started at http://127.17.222.254:38453/ using document root <none> and password file <none>
I20260812 06:19:19.534778 18299 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:19.534852 18299 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:19.534935 18299 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:19.535351 18299 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554132257-18299-0/minicluster-data/master-0-root/instance:
uuid: "54e683e388274c09afcfef796c28a168"
format_stamp: "Formatted at 2026-08-12 06:19:19 on dist-test-slave-3h5h"
I20260812 06:19:19.536885 18299 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:19.537835 18600 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:19.538249 18299 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:19.538316 18299 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554132257-18299-0/minicluster-data/master-0-root
uuid: "54e683e388274c09afcfef796c28a168"
format_stamp: "Formatted at 2026-08-12 06:19:19 on dist-test-slave-3h5h"
I20260812 06:19:19.538407 18299 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554132257-18299-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554132257-18299-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554132257-18299-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:19.550909 18299 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:19.551328 18299 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:19.555902 18299 rpc_server.cc:307] RPC server started. Bound to: 127.17.222.254:42323
I20260812 06:19:19.556232 18679 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.17.222.254:42323 every 8 connection(s)
I20260812 06:19:19.571199 18680 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:19.573659 18680 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 54e683e388274c09afcfef796c28a168: Bootstrap starting.
I20260812 06:19:19.574563 18680 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 54e683e388274c09afcfef796c28a168: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:19.575716 18680 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 54e683e388274c09afcfef796c28a168: No bootstrap required, opened a new log
I20260812 06:19:19.576273 18680 raft_consensus.cc:359] T 00000000000000000000000000000000 P 54e683e388274c09afcfef796c28a168 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "54e683e388274c09afcfef796c28a168" member_type: VOTER }
I20260812 06:19:19.576366 18680 raft_consensus.cc:385] T 00000000000000000000000000000000 P 54e683e388274c09afcfef796c28a168 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:19.576428 18680 raft_consensus.cc:740] T 00000000000000000000000000000000 P 54e683e388274c09afcfef796c28a168 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 54e683e388274c09afcfef796c28a168, State: Initialized, Role: FOLLOWER
I20260812 06:19:19.576630 18680 consensus_queue.cc:260] T 00000000000000000000000000000000 P 54e683e388274c09afcfef796c28a168 [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: "54e683e388274c09afcfef796c28a168" member_type: VOTER }
I20260812 06:19:19.576714 18680 raft_consensus.cc:399] T 00000000000000000000000000000000 P 54e683e388274c09afcfef796c28a168 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:19.576740 18680 raft_consensus.cc:493] T 00000000000000000000000000000000 P 54e683e388274c09afcfef796c28a168 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:19.576820 18680 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 54e683e388274c09afcfef796c28a168 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:19.577629 18680 raft_consensus.cc:515] T 00000000000000000000000000000000 P 54e683e388274c09afcfef796c28a168 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "54e683e388274c09afcfef796c28a168" member_type: VOTER }
I20260812 06:19:19.577790 18680 leader_election.cc:304] T 00000000000000000000000000000000 P 54e683e388274c09afcfef796c28a168 [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: 54e683e388274c09afcfef796c28a168; no voters: 
I20260812 06:19:19.578020 18680 leader_election.cc:290] T 00000000000000000000000000000000 P 54e683e388274c09afcfef796c28a168 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:19.578152 18684 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 54e683e388274c09afcfef796c28a168 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:19.578395 18684 raft_consensus.cc:697] T 00000000000000000000000000000000 P 54e683e388274c09afcfef796c28a168 [term 1 LEADER]: Becoming Leader. State: Replica: 54e683e388274c09afcfef796c28a168, State: Running, Role: LEADER
I20260812 06:19:19.578576 18680 sys_catalog.cc:565] T 00000000000000000000000000000000 P 54e683e388274c09afcfef796c28a168 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:19.578531 18684 consensus_queue.cc:237] T 00000000000000000000000000000000 P 54e683e388274c09afcfef796c28a168 [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: "54e683e388274c09afcfef796c28a168" member_type: VOTER }
I20260812 06:19:19.579041 18689 sys_catalog.cc:455] T 00000000000000000000000000000000 P 54e683e388274c09afcfef796c28a168 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 54e683e388274c09afcfef796c28a168. Latest consensus state: current_term: 1 leader_uuid: "54e683e388274c09afcfef796c28a168" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "54e683e388274c09afcfef796c28a168" member_type: VOTER } }
I20260812 06:19:19.579026 18685 sys_catalog.cc:455] T 00000000000000000000000000000000 P 54e683e388274c09afcfef796c28a168 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "54e683e388274c09afcfef796c28a168" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "54e683e388274c09afcfef796c28a168" member_type: VOTER } }
I20260812 06:19:19.579213 18689 sys_catalog.cc:458] T 00000000000000000000000000000000 P 54e683e388274c09afcfef796c28a168 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:19.579279 18685 sys_catalog.cc:458] T 00000000000000000000000000000000 P 54e683e388274c09afcfef796c28a168 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:19.579762 18693 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:19.580444 18693 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:19.580776 18299 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:19.582522 18693 catalog_manager.cc:1383] Generated new cluster ID: ffa3b951bbba430b9aee1696f74ae5bf
I20260812 06:19:19.582588 18693 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:19.596284 18693 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:19.597189 18693 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:19.604903 18693 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 54e683e388274c09afcfef796c28a168: Generated new TSK 0
I20260812 06:19:19.605118 18693 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:19.613545 18299 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:19.616120 18717 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:19.616155 18720 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:19.616336 18299 server_base.cc:1061] running on GCE node
W20260812 06:19:19.616420 18722 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:19.616706 18299 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:19.616775 18299 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:19.616801 18299 hybrid_clock.cc:648] HybridClock initialized: now 1786515559616801 us; error 0 us; skew 500 ppm
I20260812 06:19:19.617662 18299 webserver.cc:533] Webserver started at http://127.17.222.193:36727/ using document root <none> and password file <none>
I20260812 06:19:19.617843 18299 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:19.617918 18299 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:19.617996 18299 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:19.618453 18299 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554132257-18299-0/minicluster-data/ts-0-root/instance:
uuid: "ed55c514233f4454a93b63aa1d0d8716"
format_stamp: "Formatted at 2026-08-12 06:19:19 on dist-test-slave-3h5h"
I20260812 06:19:19.619982 18299 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:19:19.621016 18731 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:19.621243 18299 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:19.621335 18299 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554132257-18299-0/minicluster-data/ts-0-root
uuid: "ed55c514233f4454a93b63aa1d0d8716"
format_stamp: "Formatted at 2026-08-12 06:19:19 on dist-test-slave-3h5h"
I20260812 06:19:19.621425 18299 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554132257-18299-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554132257-18299-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554132257-18299-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:19.627310 18299 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:19.627651 18299 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:19.627942 18299 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:19.628484 18299 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:19.628547 18299 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:19.628608 18299 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:19.628643 18299 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:19.633293 18299 rpc_server.cc:307] RPC server started. Bound to: 127.17.222.193:36519
I20260812 06:19:19.633320 18833 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.17.222.193:36519 every 8 connection(s)
I20260812 06:19:19.642818 18834 heartbeater.cc:344] Connected to a master server at 127.17.222.254:42323
I20260812 06:19:19.642944 18834 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:19.643178 18834 heartbeater.cc:507] Master 127.17.222.254:42323 requested a full tablet report, sending...
I20260812 06:19:19.643875 18628 ts_manager.cc:194] Registered new tserver with Master: ed55c514233f4454a93b63aa1d0d8716 (127.17.222.193:36519)
I20260812 06:19:19.644650 18628 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:57850
I20260812 06:19:19.644936 18299 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011175543s
I20260812 06:19:19.652254 18628 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:57866:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:19.662216 18778 tablet_service.cc:1511] Processing CreateTablet for tablet 640606d987734e999d30fc3bbfc1435d (DEFAULT_TABLE table=heavy-update-compaction-test [id=5495fbe1dc2d42b797925adb973175ba]), partition=
I20260812 06:19:19.662537 18778 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 640606d987734e999d30fc3bbfc1435d. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:19.664849 18852 tablet_bootstrap.cc:492] T 640606d987734e999d30fc3bbfc1435d P ed55c514233f4454a93b63aa1d0d8716: Bootstrap starting.
I20260812 06:19:19.665932 18852 tablet_bootstrap.cc:654] T 640606d987734e999d30fc3bbfc1435d P ed55c514233f4454a93b63aa1d0d8716: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:19.667203 18852 tablet_bootstrap.cc:492] T 640606d987734e999d30fc3bbfc1435d P ed55c514233f4454a93b63aa1d0d8716: No bootstrap required, opened a new log
I20260812 06:19:19.667290 18852 ts_tablet_manager.cc:1403] T 640606d987734e999d30fc3bbfc1435d P ed55c514233f4454a93b63aa1d0d8716: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:19:19.667820 18852 raft_consensus.cc:359] T 640606d987734e999d30fc3bbfc1435d P ed55c514233f4454a93b63aa1d0d8716 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ed55c514233f4454a93b63aa1d0d8716" member_type: VOTER last_known_addr { host: "127.17.222.193" port: 36519 } }
I20260812 06:19:19.667912 18852 raft_consensus.cc:385] T 640606d987734e999d30fc3bbfc1435d P ed55c514233f4454a93b63aa1d0d8716 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:19.667935 18852 raft_consensus.cc:740] T 640606d987734e999d30fc3bbfc1435d P ed55c514233f4454a93b63aa1d0d8716 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: ed55c514233f4454a93b63aa1d0d8716, State: Initialized, Role: FOLLOWER
I20260812 06:19:19.668080 18852 consensus_queue.cc:260] T 640606d987734e999d30fc3bbfc1435d P ed55c514233f4454a93b63aa1d0d8716 [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: "ed55c514233f4454a93b63aa1d0d8716" member_type: VOTER last_known_addr { host: "127.17.222.193" port: 36519 } }
I20260812 06:19:19.668174 18852 raft_consensus.cc:399] T 640606d987734e999d30fc3bbfc1435d P ed55c514233f4454a93b63aa1d0d8716 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:19.668233 18852 raft_consensus.cc:493] T 640606d987734e999d30fc3bbfc1435d P ed55c514233f4454a93b63aa1d0d8716 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:19.668294 18852 raft_consensus.cc:3060] T 640606d987734e999d30fc3bbfc1435d P ed55c514233f4454a93b63aa1d0d8716 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:19.669130 18852 raft_consensus.cc:515] T 640606d987734e999d30fc3bbfc1435d P ed55c514233f4454a93b63aa1d0d8716 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ed55c514233f4454a93b63aa1d0d8716" member_type: VOTER last_known_addr { host: "127.17.222.193" port: 36519 } }
I20260812 06:19:19.669281 18852 leader_election.cc:304] T 640606d987734e999d30fc3bbfc1435d P ed55c514233f4454a93b63aa1d0d8716 [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: ed55c514233f4454a93b63aa1d0d8716; no voters: 
I20260812 06:19:19.669508 18852 leader_election.cc:290] T 640606d987734e999d30fc3bbfc1435d P ed55c514233f4454a93b63aa1d0d8716 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:19.669713 18856 raft_consensus.cc:2804] T 640606d987734e999d30fc3bbfc1435d P ed55c514233f4454a93b63aa1d0d8716 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:19.669891 18834 heartbeater.cc:499] Master 127.17.222.254:42323 was elected leader, sending a full tablet report...
I20260812 06:19:19.669972 18856 raft_consensus.cc:697] T 640606d987734e999d30fc3bbfc1435d P ed55c514233f4454a93b63aa1d0d8716 [term 1 LEADER]: Becoming Leader. State: Replica: ed55c514233f4454a93b63aa1d0d8716, State: Running, Role: LEADER
I20260812 06:19:19.670137 18856 consensus_queue.cc:237] T 640606d987734e999d30fc3bbfc1435d P ed55c514233f4454a93b63aa1d0d8716 [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: "ed55c514233f4454a93b63aa1d0d8716" member_type: VOTER last_known_addr { host: "127.17.222.193" port: 36519 } }
I20260812 06:19:19.670167 18852 ts_tablet_manager.cc:1434] T 640606d987734e999d30fc3bbfc1435d P ed55c514233f4454a93b63aa1d0d8716: Time spent starting tablet: real 0.003s	user 0.001s	sys 0.003s
I20260812 06:19:19.671583 18628 catalog_manager.cc:5719] T 640606d987734e999d30fc3bbfc1435d P ed55c514233f4454a93b63aa1d0d8716 reported cstate change: term changed from 0 to 1, leader changed from <none> to ed55c514233f4454a93b63aa1d0d8716 (127.17.222.193). New cstate: current_term: 1 leader_uuid: "ed55c514233f4454a93b63aa1d0d8716" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ed55c514233f4454a93b63aa1d0d8716" member_type: VOTER last_known_addr { host: "127.17.222.193" port: 36519 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:19.738058 18299 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.060s	user 0.013s	sys 0.012s
I20260812 06:19:19.884374 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling FlushMRSOp(640606d987734e999d30fc3bbfc1435d): perf score=19.054940
I20260812 06:19:20.046521 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: FlushMRSOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.162s	user 0.121s	sys 0.039s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":101,"dirs.run_cpu_time_us":204,"dirs.run_wall_time_us":1082,"drs_written":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4,"lbm_write_time_us":43719,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":3200,"update_count":1500}
I20260812 06:19:20.047173 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling LogGCOp(640606d987734e999d30fc3bbfc1435d): free 20743831 bytes of WAL
I20260812 06:19:20.047405 18744 log_reader.cc:385] T 640606d987734e999d30fc3bbfc1435d: removed 2 log segments from log reader
I20260812 06:19:20.047449 18744 log.cc:1079] T 640606d987734e999d30fc3bbfc1435d P ed55c514233f4454a93b63aa1d0d8716: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/640606d987734e999d30fc3bbfc1435d/wal-000000001 (ops 1-6)
I20260812 06:19:20.047501 18744 log.cc:1079] T 640606d987734e999d30fc3bbfc1435d P ed55c514233f4454a93b63aa1d0d8716: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/640606d987734e999d30fc3bbfc1435d/wal-000000002 (ops 7-11)
I20260812 06:19:20.052069 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: LogGCOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.005s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:19:20.052456 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling UndoDeltaBlockGCOp(640606d987734e999d30fc3bbfc1435d): 16411392 bytes on disk
I20260812 06:19:20.052996 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: UndoDeltaBlockGCOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":97,"lbm_reads_lt_1ms":4}
I20260812 06:19:20.053628 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d): perf score=2.188937
I20260812 06:19:20.070024 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.016s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6017,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:20.070547 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling MajorDeltaCompactionOp(640606d987734e999d30fc3bbfc1435d): perf score=1.000000
I20260812 06:19:20.214003 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: MajorDeltaCompactionOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.143s	user 0.108s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1457,"lbm_read_time_us":9773,"lbm_reads_lt_1ms":460,"lbm_write_time_us":24016,"lbm_writes_lt_1ms":443,"mutex_wait_us":305,"peak_mem_usage":50689328,"reinsert_count":0,"thread_start_us":383,"threads_started":5,"update_count":2000}
I20260812 06:19:20.214643 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d): perf score=14.095187
I20260812 06:19:20.264011 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.049s	user 0.026s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22810,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:20.264518 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d): perf score=2.188937
I20260812 06:19:20.281107 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.016s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6304,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:20.281600 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling MajorDeltaCompactionOp(640606d987734e999d30fc3bbfc1435d): perf score=1.000000
I20260812 06:19:20.436863 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: MajorDeltaCompactionOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.155s	user 0.091s	sys 0.061s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":148,"lbm_read_time_us":9423,"lbm_reads_lt_1ms":568,"lbm_write_time_us":29789,"lbm_writes_lt_1ms":543,"mutex_wait_us":57,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13440,"update_count":2500}
I20260812 06:19:20.437601 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d): perf score=12.110812
I20260812 06:19:20.483855 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.046s	user 0.027s	sys 0.016s Metrics: {"bytes_written":13620267,"delete_count":0,"lbm_write_time_us":21632,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":333,"reinsert_count":0,"update_count":1660}
I20260812 06:19:20.484465 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d): perf score=2.188937
I20260812 06:19:20.503331 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.019s	user 0.007s	sys 0.000s Metrics: {"bytes_written":3200109,"delete_count":0,"lbm_write_time_us":3190,"lbm_writes_lt_1ms":81,"reinsert_count":0,"update_count":390}
I20260812 06:19:20.503801 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d): perf score=2.188937
I20260812 06:19:20.514076 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3765,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:20.514554 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling MajorDeltaCompactionOp(640606d987734e999d30fc3bbfc1435d): perf score=1.000000
I20260812 06:19:20.697227 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: MajorDeltaCompactionOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.182s	user 0.131s	sys 0.051s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774781,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":789,"lbm_read_time_us":13078,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29515,"lbm_writes_lt_1ms":543,"mutex_wait_us":27,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":30080,"update_count":2500}
I20260812 06:19:20.697932 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d): perf score=14.095187
I20260812 06:19:20.756480 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.058s	user 0.032s	sys 0.013s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":21665,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:20.757068 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d): perf score=2.188937
I20260812 06:19:20.767784 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4181,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:20.768265 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling MajorDeltaCompactionOp(640606d987734e999d30fc3bbfc1435d): perf score=1.000000
I20260812 06:19:20.963505 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: MajorDeltaCompactionOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.195s	user 0.131s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1158,"lbm_read_time_us":14348,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31164,"lbm_writes_lt_1ms":543,"mutex_wait_us":320,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6784,"update_count":2500}
I20260812 06:19:20.964233 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d): perf score=14.095187
I20260812 06:19:21.030984 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.067s	user 0.045s	sys 0.010s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21011,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:21.031716 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d): perf score=2.188937
I20260812 06:19:21.052794 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.021s	user 0.014s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7971,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:21.053586 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling MajorDeltaCompactionOp(640606d987734e999d30fc3bbfc1435d): perf score=1.000000
I20260812 06:19:21.272677 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: MajorDeltaCompactionOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.219s	user 0.150s	sys 0.065s 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":651,"lbm_read_time_us":16158,"lbm_reads_lt_1ms":572,"lbm_write_time_us":38529,"lbm_writes_lt_1ms":543,"mutex_wait_us":28,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8704,"update_count":2500}
I20260812 06:19:21.273458 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d): perf score=10.126437
I20260812 06:19:21.330694 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.056s	user 0.041s	sys 0.007s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":21226,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:21.331411 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d): perf score=2.188937
I20260812 06:19:21.350875 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.019s	user 0.013s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":7570,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:21.351570 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling FlushMRSOp(640606d987734e999d30fc3bbfc1435d): perf score=1.000000
I20260812 06:19:21.389050 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: FlushMRSOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.037s	user 0.034s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":55,"dirs.run_cpu_time_us":189,"dirs.run_wall_time_us":1480,"drs_written":1,"lbm_read_time_us":93,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1617,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:21.389762 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling LogGCOp(640606d987734e999d30fc3bbfc1435d): free 112239366 bytes of WAL
I20260812 06:19:21.390019 18744 log_reader.cc:385] T 640606d987734e999d30fc3bbfc1435d: removed 11 log segments from log reader
I20260812 06:19:21.390090 18744 log.cc:1079] T 640606d987734e999d30fc3bbfc1435d P ed55c514233f4454a93b63aa1d0d8716: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/640606d987734e999d30fc3bbfc1435d/wal-000000003 (ops 12-16)
I20260812 06:19:21.390187 18744 log.cc:1079] T 640606d987734e999d30fc3bbfc1435d P ed55c514233f4454a93b63aa1d0d8716: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/640606d987734e999d30fc3bbfc1435d/wal-000000004 (ops 17-21)
I20260812 06:19:21.390259 18744 log.cc:1079] T 640606d987734e999d30fc3bbfc1435d P ed55c514233f4454a93b63aa1d0d8716: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/640606d987734e999d30fc3bbfc1435d/wal-000000005 (ops 22-26)
I20260812 06:19:21.390312 18744 log.cc:1079] T 640606d987734e999d30fc3bbfc1435d P ed55c514233f4454a93b63aa1d0d8716: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/640606d987734e999d30fc3bbfc1435d/wal-000000006 (ops 27-31)
I20260812 06:19:21.390362 18744 log.cc:1079] T 640606d987734e999d30fc3bbfc1435d P ed55c514233f4454a93b63aa1d0d8716: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/640606d987734e999d30fc3bbfc1435d/wal-000000007 (ops 32-36)
I20260812 06:19:21.390409 18744 log.cc:1079] T 640606d987734e999d30fc3bbfc1435d P ed55c514233f4454a93b63aa1d0d8716: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/640606d987734e999d30fc3bbfc1435d/wal-000000008 (ops 37-41)
I20260812 06:19:21.390479 18744 log.cc:1079] T 640606d987734e999d30fc3bbfc1435d P ed55c514233f4454a93b63aa1d0d8716: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/640606d987734e999d30fc3bbfc1435d/wal-000000009 (ops 42-46)
I20260812 06:19:21.390529 18744 log.cc:1079] T 640606d987734e999d30fc3bbfc1435d P ed55c514233f4454a93b63aa1d0d8716: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/640606d987734e999d30fc3bbfc1435d/wal-000000010 (ops 47-50)
I20260812 06:19:21.390578 18744 log.cc:1079] T 640606d987734e999d30fc3bbfc1435d P ed55c514233f4454a93b63aa1d0d8716: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/640606d987734e999d30fc3bbfc1435d/wal-000000011 (ops 51-55)
I20260812 06:19:21.390626 18744 log.cc:1079] T 640606d987734e999d30fc3bbfc1435d P ed55c514233f4454a93b63aa1d0d8716: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/640606d987734e999d30fc3bbfc1435d/wal-000000012 (ops 56-60)
I20260812 06:19:21.390674 18744 log.cc:1079] T 640606d987734e999d30fc3bbfc1435d P ed55c514233f4454a93b63aa1d0d8716: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/640606d987734e999d30fc3bbfc1435d/wal-000000013 (ops 61-65)
I20260812 06:19:21.412194 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: LogGCOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.022s	user 0.000s	sys 0.019s Metrics: {}
I20260812 06:19:21.412928 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d): perf score=2.188937
I20260812 06:19:21.435772 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.023s	user 0.004s	sys 0.012s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":8348,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":102,"reinsert_count":0,"update_count":500}
I20260812 06:19:21.436228 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling UndoDeltaBlockGCOp(640606d987734e999d30fc3bbfc1435d): 447 bytes on disk
I20260812 06:19:21.436654 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: UndoDeltaBlockGCOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4}
I20260812 06:19:21.437126 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling MajorDeltaCompactionOp(640606d987734e999d30fc3bbfc1435d): perf score=1.000000
I20260812 06:19:21.623566 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: MajorDeltaCompactionOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.186s	user 0.137s	sys 0.049s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774807,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":953,"lbm_read_time_us":12045,"lbm_reads_lt_1ms":565,"lbm_write_time_us":29032,"lbm_writes_lt_1ms":543,"mutex_wait_us":308,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11904,"thread_start_us":81,"threads_started":1,"update_count":2500}
I20260812 06:19:21.624274 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d): perf score=14.095187
I20260812 06:19:21.672478 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.048s	user 0.038s	sys 0.007s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":21480,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:21.673084 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d): perf score=2.188937
I20260812 06:19:21.697007 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.024s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102660,"delete_count":0,"lbm_write_time_us":5469,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:21.697499 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling MajorDeltaCompactionOp(640606d987734e999d30fc3bbfc1435d): perf score=1.000000
I20260812 06:19:21.876109 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: MajorDeltaCompactionOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.178s	user 0.136s	sys 0.039s 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":290,"lbm_read_time_us":11364,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27277,"lbm_writes_lt_1ms":543,"mutex_wait_us":33,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":46336,"update_count":2500}
I20260812 06:19:21.876802 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d): perf score=14.095187
I20260812 06:19:21.929975 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.053s	user 0.035s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22782,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:21.930517 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d): perf score=2.188937
I20260812 06:19:21.942831 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4466,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:21.943825 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling MajorDeltaCompactionOp(640606d987734e999d30fc3bbfc1435d): perf score=1.000000
I20260812 06:19:22.135336 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: MajorDeltaCompactionOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.191s	user 0.113s	sys 0.065s 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":419,"lbm_read_time_us":13752,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29795,"lbm_writes_lt_1ms":543,"mutex_wait_us":63,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10496,"update_count":2500}
I20260812 06:19:22.135979 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d): perf score=14.095187
I20260812 06:19:22.185659 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.049s	user 0.033s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23339,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:22.186133 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d): perf score=2.188937
I20260812 06:19:22.197715 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4115,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:22.198179 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling MajorDeltaCompactionOp(640606d987734e999d30fc3bbfc1435d): perf score=1.000000
I20260812 06:19:22.339541 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: MajorDeltaCompactionOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.141s	user 0.108s	sys 0.032s 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":859,"lbm_read_time_us":10047,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29843,"lbm_writes_lt_1ms":543,"mutex_wait_us":309,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13696,"update_count":2500}
I20260812 06:19:22.340317 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d): perf score=11.118625
I20260812 06:19:22.373287 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.033s	user 0.013s	sys 0.019s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15490,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:19:22.374997 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d): perf score=2.188937
I20260812 06:19:22.394018 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.019s	user 0.002s	sys 0.012s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6397,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:22.394486 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling MajorDeltaCompactionOp(640606d987734e999d30fc3bbfc1435d): perf score=1.000000
I20260812 06:19:22.527266 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: MajorDeltaCompactionOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.133s	user 0.110s	sys 0.022s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1223,"lbm_read_time_us":8378,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26469,"lbm_writes_lt_1ms":443,"mutex_wait_us":294,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12032,"update_count":2000}
I20260812 06:19:22.527848 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d): perf score=10.126437
I20260812 06:19:22.575179 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.047s	user 0.025s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18372,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:19:22.575731 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d): perf score=2.188937
I20260812 06:19:22.586421 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4079,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:22.587129 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling MajorDeltaCompactionOp(640606d987734e999d30fc3bbfc1435d): perf score=1.000000
I20260812 06:19:22.716454 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: MajorDeltaCompactionOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.129s	user 0.091s	sys 0.038s 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":268,"lbm_read_time_us":9470,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25069,"lbm_writes_lt_1ms":443,"mutex_wait_us":47,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":17024,"update_count":2000}
I20260812 06:19:22.717253 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d): perf score=10.126437
I20260812 06:19:22.769483 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.052s	user 0.024s	sys 0.016s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":13605,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:22.770099 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d): perf score=2.188937
I20260812 06:19:22.780962 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4160,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:22.781419 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling FlushMRSOp(640606d987734e999d30fc3bbfc1435d): perf score=1.000000
I20260812 06:19:22.827206 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: FlushMRSOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.046s	user 0.029s	sys 0.003s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":93,"dirs.run_cpu_time_us":259,"dirs.run_wall_time_us":1611,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2204,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:22.827953 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling LogGCOp(640606d987734e999d30fc3bbfc1435d): free 120553331 bytes of WAL
I20260812 06:19:22.828236 18744 log_reader.cc:385] T 640606d987734e999d30fc3bbfc1435d: removed 12 log segments from log reader
I20260812 06:19:22.828298 18744 log.cc:1079] T 640606d987734e999d30fc3bbfc1435d P ed55c514233f4454a93b63aa1d0d8716: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/640606d987734e999d30fc3bbfc1435d/wal-000000014 (ops 66-70)
I20260812 06:19:22.828337 18744 log.cc:1079] T 640606d987734e999d30fc3bbfc1435d P ed55c514233f4454a93b63aa1d0d8716: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/640606d987734e999d30fc3bbfc1435d/wal-000000015 (ops 71-74)
I20260812 06:19:22.828366 18744 log.cc:1079] T 640606d987734e999d30fc3bbfc1435d P ed55c514233f4454a93b63aa1d0d8716: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/640606d987734e999d30fc3bbfc1435d/wal-000000016 (ops 75-79)
I20260812 06:19:22.828393 18744 log.cc:1079] T 640606d987734e999d30fc3bbfc1435d P ed55c514233f4454a93b63aa1d0d8716: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/640606d987734e999d30fc3bbfc1435d/wal-000000017 (ops 80-84)
I20260812 06:19:22.828428 18744 log.cc:1079] T 640606d987734e999d30fc3bbfc1435d P ed55c514233f4454a93b63aa1d0d8716: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/640606d987734e999d30fc3bbfc1435d/wal-000000018 (ops 85-89)
I20260812 06:19:22.828460 18744 log.cc:1079] T 640606d987734e999d30fc3bbfc1435d P ed55c514233f4454a93b63aa1d0d8716: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/640606d987734e999d30fc3bbfc1435d/wal-000000019 (ops 90-94)
I20260812 06:19:22.828487 18744 log.cc:1079] T 640606d987734e999d30fc3bbfc1435d P ed55c514233f4454a93b63aa1d0d8716: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/640606d987734e999d30fc3bbfc1435d/wal-000000020 (ops 95-99)
I20260812 06:19:22.828516 18744 log.cc:1079] T 640606d987734e999d30fc3bbfc1435d P ed55c514233f4454a93b63aa1d0d8716: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/640606d987734e999d30fc3bbfc1435d/wal-000000021 (ops 100-104)
I20260812 06:19:22.828537 18744 log.cc:1079] T 640606d987734e999d30fc3bbfc1435d P ed55c514233f4454a93b63aa1d0d8716: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/640606d987734e999d30fc3bbfc1435d/wal-000000022 (ops 105-109)
I20260812 06:19:22.828579 18744 log.cc:1079] T 640606d987734e999d30fc3bbfc1435d P ed55c514233f4454a93b63aa1d0d8716: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/640606d987734e999d30fc3bbfc1435d/wal-000000023 (ops 110-114)
I20260812 06:19:22.828606 18744 log.cc:1079] T 640606d987734e999d30fc3bbfc1435d P ed55c514233f4454a93b63aa1d0d8716: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/640606d987734e999d30fc3bbfc1435d/wal-000000024 (ops 115-118)
I20260812 06:19:22.828629 18744 log.cc:1079] T 640606d987734e999d30fc3bbfc1435d P ed55c514233f4454a93b63aa1d0d8716: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/640606d987734e999d30fc3bbfc1435d/wal-000000025 (ops 119-123)
I20260812 06:19:22.859752 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: LogGCOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.032s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:19:22.860198 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d): perf score=2.188937
I20260812 06:19:22.885046 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.025s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5398,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:22.885527 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling UndoDeltaBlockGCOp(640606d987734e999d30fc3bbfc1435d): 448 bytes on disk
I20260812 06:19:22.885959 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: UndoDeltaBlockGCOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:19:22.886469 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d): perf score=2.188937
I20260812 06:19:22.897043 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3942,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:22.897488 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling MajorDeltaCompactionOp(640606d987734e999d30fc3bbfc1435d): perf score=1.000000
I20260812 06:19:23.129315 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: MajorDeltaCompactionOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.232s	user 0.163s	sys 0.067s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877337,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":959,"lbm_read_time_us":13971,"lbm_reads_lt_1ms":674,"lbm_write_time_us":38248,"lbm_writes_lt_1ms":643,"mutex_wait_us":333,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3584,"thread_start_us":84,"threads_started":1,"update_count":3000}
I20260812 06:19:23.129935 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d): perf score=15.087375
I20260812 06:19:23.172076 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.042s	user 0.027s	sys 0.012s Metrics: {"bytes_written":16820141,"delete_count":0,"lbm_write_time_us":18136,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:19:23.173472 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d): perf score=2.188937
I20260812 06:19:23.201781 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.028s	user 0.011s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5355,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:23.202287 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d): perf score=2.188937
I20260812 06:19:23.213776 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.011s	user 0.008s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4293,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:23.214264 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling MajorDeltaCompactionOp(640606d987734e999d30fc3bbfc1435d): perf score=1.000000
I20260812 06:19:23.422720 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: MajorDeltaCompactionOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.208s	user 0.138s	sys 0.065s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877205,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":210,"lbm_read_time_us":14281,"lbm_reads_lt_1ms":673,"lbm_write_time_us":37024,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":642,"mutex_wait_us":32,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":11392,"update_count":3000}
I20260812 06:19:23.423549 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d): perf score=16.079562
I20260812 06:19:23.504218 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.080s	user 0.044s	sys 0.019s Metrics: {"bytes_written":18091889,"delete_count":0,"lbm_write_time_us":29766,"lbm_writes_lt_1ms":444,"reinsert_count":0,"update_count":2205}
I20260812 06:19:23.504760 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d): perf score=5.165500
I20260812 06:19:23.530979 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.026s	user 0.013s	sys 0.004s Metrics: {"bytes_written":6523094,"delete_count":0,"lbm_write_time_us":8098,"lbm_writes_lt_1ms":162,"reinsert_count":0,"update_count":795}
I20260812 06:19:23.531562 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling MajorDeltaCompactionOp(640606d987734e999d30fc3bbfc1435d): perf score=1.000000
I20260812 06:19:23.726365 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: MajorDeltaCompactionOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.195s	user 0.119s	sys 0.076s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877105,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":171,"lbm_read_time_us":12633,"lbm_reads_lt_1ms":664,"lbm_write_time_us":33848,"lbm_writes_lt_1ms":643,"mutex_wait_us":26,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":18688,"update_count":3000}
I20260812 06:19:23.727288 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d): perf score=14.095187
I20260812 06:19:23.770764 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.043s	user 0.024s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18186,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:23.771463 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d): perf score=2.188937
I20260812 06:19:23.782819 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4405,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:23.783361 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling MajorDeltaCompactionOp(640606d987734e999d30fc3bbfc1435d): perf score=1.000000
I20260812 06:19:23.968530 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: MajorDeltaCompactionOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.185s	user 0.136s	sys 0.044s 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":535,"lbm_read_time_us":14378,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29531,"lbm_writes_lt_1ms":543,"mutex_wait_us":204,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11136,"update_count":2500}
I20260812 06:19:23.969151 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d): perf score=11.118625
I20260812 06:19:24.020121 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.051s	user 0.029s	sys 0.019s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":15957,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:24.020803 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d): perf score=2.188937
I20260812 06:19:24.042656 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.022s	user 0.003s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5137,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:24.043197 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling MajorDeltaCompactionOp(640606d987734e999d30fc3bbfc1435d): perf score=1.000000
I20260812 06:19:24.198750 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: MajorDeltaCompactionOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.155s	user 0.092s	sys 0.060s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672270,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":654,"lbm_read_time_us":9031,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24839,"lbm_writes_lt_1ms":443,"mutex_wait_us":282,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4608,"update_count":2000}
I20260812 06:19:24.199404 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d): perf score=14.095187
I20260812 06:19:24.252362 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.053s	user 0.031s	sys 0.015s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":22307,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:24.252980 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d): perf score=2.188937
I20260812 06:19:24.264628 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4119,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:24.265169 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling FlushMRSOp(640606d987734e999d30fc3bbfc1435d): perf score=1.000000
I20260812 06:19:24.295567 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: FlushMRSOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.030s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":81,"dirs.run_cpu_time_us":262,"dirs.run_wall_time_us":1565,"drs_written":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1791,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:24.296514 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling LogGCOp(640606d987734e999d30fc3bbfc1435d): free 112692649 bytes of WAL
I20260812 06:19:24.296767 18744 log_reader.cc:385] T 640606d987734e999d30fc3bbfc1435d: removed 11 log segments from log reader
I20260812 06:19:24.296849 18744 log.cc:1079] T 640606d987734e999d30fc3bbfc1435d P ed55c514233f4454a93b63aa1d0d8716: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/640606d987734e999d30fc3bbfc1435d/wal-000000026 (ops 124-128)
I20260812 06:19:24.296931 18744 log.cc:1079] T 640606d987734e999d30fc3bbfc1435d P ed55c514233f4454a93b63aa1d0d8716: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/640606d987734e999d30fc3bbfc1435d/wal-000000027 (ops 129-133)
I20260812 06:19:24.296969 18744 log.cc:1079] T 640606d987734e999d30fc3bbfc1435d P ed55c514233f4454a93b63aa1d0d8716: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/640606d987734e999d30fc3bbfc1435d/wal-000000028 (ops 134-138)
I20260812 06:19:24.297001 18744 log.cc:1079] T 640606d987734e999d30fc3bbfc1435d P ed55c514233f4454a93b63aa1d0d8716: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/640606d987734e999d30fc3bbfc1435d/wal-000000029 (ops 139-143)
I20260812 06:19:24.297030 18744 log.cc:1079] T 640606d987734e999d30fc3bbfc1435d P ed55c514233f4454a93b63aa1d0d8716: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/640606d987734e999d30fc3bbfc1435d/wal-000000030 (ops 144-148)
I20260812 06:19:24.297065 18744 log.cc:1079] T 640606d987734e999d30fc3bbfc1435d P ed55c514233f4454a93b63aa1d0d8716: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/640606d987734e999d30fc3bbfc1435d/wal-000000031 (ops 149-153)
I20260812 06:19:24.297097 18744 log.cc:1079] T 640606d987734e999d30fc3bbfc1435d P ed55c514233f4454a93b63aa1d0d8716: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/640606d987734e999d30fc3bbfc1435d/wal-000000032 (ops 154-158)
I20260812 06:19:24.297133 18744 log.cc:1079] T 640606d987734e999d30fc3bbfc1435d P ed55c514233f4454a93b63aa1d0d8716: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/640606d987734e999d30fc3bbfc1435d/wal-000000033 (ops 159-163)
I20260812 06:19:24.297170 18744 log.cc:1079] T 640606d987734e999d30fc3bbfc1435d P ed55c514233f4454a93b63aa1d0d8716: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/640606d987734e999d30fc3bbfc1435d/wal-000000034 (ops 164-168)
I20260812 06:19:24.297209 18744 log.cc:1079] T 640606d987734e999d30fc3bbfc1435d P ed55c514233f4454a93b63aa1d0d8716: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/640606d987734e999d30fc3bbfc1435d/wal-000000035 (ops 169-173)
I20260812 06:19:24.297245 18744 log.cc:1079] T 640606d987734e999d30fc3bbfc1435d P ed55c514233f4454a93b63aa1d0d8716: Deleting log segment in path: /tmp/dist-test-taskLoUCqq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515554132257-18299-0/minicluster-data/ts-0-root/wals/640606d987734e999d30fc3bbfc1435d/wal-000000036 (ops 174-178)
I20260812 06:19:24.323148 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: LogGCOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.026s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:24.326938 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling UndoDeltaBlockGCOp(640606d987734e999d30fc3bbfc1435d): 447 bytes on disk
I20260812 06:19:24.327538 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: UndoDeltaBlockGCOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4}
I20260812 06:19:24.328253 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d): perf score=2.188937
I20260812 06:19:24.346163 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.018s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5020,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:24.346704 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d): perf score=2.188937
I20260812 06:19:24.358352 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4572,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:24.358974 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling MajorDeltaCompactionOp(640606d987734e999d30fc3bbfc1435d): perf score=1.000000
I20260812 06:19:24.625757 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: MajorDeltaCompactionOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.267s	user 0.173s	sys 0.090s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979752,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":621,"lbm_read_time_us":18260,"lbm_reads_lt_1ms":774,"lbm_write_time_us":46051,"lbm_writes_lt_1ms":743,"mutex_wait_us":13,"peak_mem_usage":87969044,"reinsert_count":0,"thread_start_us":86,"threads_started":1,"update_count":3500}
I20260812 06:19:24.626633 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d): perf score=18.063937
I20260812 06:19:24.699285 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.072s	user 0.044s	sys 0.019s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":31084,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":500,"reinsert_count":0,"update_count":2500}
I20260812 06:19:24.699775 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d): perf score=2.188937
I20260812 06:19:24.711040 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.011s	user 0.001s	sys 0.008s 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:19:24.711621 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling MajorDeltaCompactionOp(640606d987734e999d30fc3bbfc1435d): perf score=1.000000
I20260812 06:19:24.924067 18299 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.186s	user 1.969s	sys 0.145s
I20260812 06:19:24.936251 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: MajorDeltaCompactionOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.224s	user 0.155s	sys 0.067s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877103,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":282,"lbm_read_time_us":15074,"lbm_reads_lt_1ms":672,"lbm_write_time_us":36851,"lbm_writes_lt_1ms":643,"mutex_wait_us":82,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6272,"update_count":3000}
I20260812 06:19:24.937124 18837 maintenance_manager.cc:419] P ed55c514233f4454a93b63aa1d0d8716: Scheduling FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d): perf score=14.095187
I20260812 06:19:24.973452 18299 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.049s	user 0.003s	sys 0.000s
I20260812 06:19:24.973951 18299 tablet_server.cc:179] TabletServer@127.17.222.193:0 shutting down...
I20260812 06:19:24.996557 18744 maintenance_manager.cc:643] P ed55c514233f4454a93b63aa1d0d8716: FlushDeltaMemStoresOp(640606d987734e999d30fc3bbfc1435d) complete. Timing: real 0.059s	user 0.026s	sys 0.029s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":27569,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:24.997357 18299 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:24.997690 18299 tablet_replica.cc:333] T 640606d987734e999d30fc3bbfc1435d P ed55c514233f4454a93b63aa1d0d8716: stopping tablet replica
I20260812 06:19:24.997825 18299 raft_consensus.cc:2243] T 640606d987734e999d30fc3bbfc1435d P ed55c514233f4454a93b63aa1d0d8716 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:24.997964 18299 raft_consensus.cc:2272] T 640606d987734e999d30fc3bbfc1435d P ed55c514233f4454a93b63aa1d0d8716 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:25.001744 18299 tablet_server.cc:196] TabletServer@127.17.222.193:0 shutdown complete.
I20260812 06:19:25.004630 18299 master.cc:562] Master@127.17.222.254:42323 shutting down...
I20260812 06:19:25.009215 18299 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 54e683e388274c09afcfef796c28a168 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:25.009389 18299 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 54e683e388274c09afcfef796c28a168 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:25.009443 18299 tablet_replica.cc:333] T 00000000000000000000000000000000 P 54e683e388274c09afcfef796c28a168: stopping tablet replica
I20260812 06:19:25.023137 18299 master.cc:584] Master@127.17.222.254:42323 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5585 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10974 ms total)

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