[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:17:25.174477 17139 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.16.188.254:40221
I20260812 06:17:25.175526 17139 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:17:25.176139 17139 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:25.182576 17150 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:25.182678 17139 server_base.cc:1061] running on GCE node
W20260812 06:17:25.182771 17147 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:25.182891 17148 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:25.183404 17139 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:25.183495 17139 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:25.183521 17139 hybrid_clock.cc:648] HybridClock initialized: now 1786515445183519 us; error 0 us; skew 500 ppm
I20260812 06:17:25.185402 17139 webserver.cc:533] Webserver started at http://127.16.188.254:38425/ using document root <none> and password file <none>
I20260812 06:17:25.185931 17139 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:25.185987 17139 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:25.186173 17139 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:25.187795 17139 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445158667-17139-0/minicluster-data/master-0-root/instance:
uuid: "9a0d150c1bdc414288bd732bfc6e3fbe"
format_stamp: "Formatted at 2026-08-12 06:17:25 on dist-test-slave-j2vl"
I20260812 06:17:25.191293 17139 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.002s	sys 0.003s
I20260812 06:17:25.193440 17158 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:25.194545 17139 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.001s	sys 0.001s
I20260812 06:17:25.194689 17139 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445158667-17139-0/minicluster-data/master-0-root
uuid: "9a0d150c1bdc414288bd732bfc6e3fbe"
format_stamp: "Formatted at 2026-08-12 06:17:25 on dist-test-slave-j2vl"
I20260812 06:17:25.194816 17139 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445158667-17139-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445158667-17139-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445158667-17139-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:25.210583 17139 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:25.211243 17139 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:17:25.211436 17139 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:25.219329 17139 rpc_server.cc:307] RPC server started. Bound to: 127.16.188.254:40221
I20260812 06:17:25.219341 17263 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.16.188.254:40221 every 8 connection(s)
I20260812 06:17:25.221709 17265 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:25.227170 17265 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 9a0d150c1bdc414288bd732bfc6e3fbe: Bootstrap starting.
I20260812 06:17:25.229569 17265 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 9a0d150c1bdc414288bd732bfc6e3fbe: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:25.230449 17265 log.cc:826] T 00000000000000000000000000000000 P 9a0d150c1bdc414288bd732bfc6e3fbe: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:25.232110 17265 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 9a0d150c1bdc414288bd732bfc6e3fbe: No bootstrap required, opened a new log
I20260812 06:17:25.234823 17265 raft_consensus.cc:359] T 00000000000000000000000000000000 P 9a0d150c1bdc414288bd732bfc6e3fbe [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9a0d150c1bdc414288bd732bfc6e3fbe" member_type: VOTER }
I20260812 06:17:25.234980 17265 raft_consensus.cc:385] T 00000000000000000000000000000000 P 9a0d150c1bdc414288bd732bfc6e3fbe [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:25.235071 17265 raft_consensus.cc:740] T 00000000000000000000000000000000 P 9a0d150c1bdc414288bd732bfc6e3fbe [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 9a0d150c1bdc414288bd732bfc6e3fbe, State: Initialized, Role: FOLLOWER
I20260812 06:17:25.235659 17265 consensus_queue.cc:260] T 00000000000000000000000000000000 P 9a0d150c1bdc414288bd732bfc6e3fbe [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: "9a0d150c1bdc414288bd732bfc6e3fbe" member_type: VOTER }
I20260812 06:17:25.235831 17265 raft_consensus.cc:399] T 00000000000000000000000000000000 P 9a0d150c1bdc414288bd732bfc6e3fbe [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:25.235898 17265 raft_consensus.cc:493] T 00000000000000000000000000000000 P 9a0d150c1bdc414288bd732bfc6e3fbe [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:25.236060 17265 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 9a0d150c1bdc414288bd732bfc6e3fbe [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:25.236833 17265 raft_consensus.cc:515] T 00000000000000000000000000000000 P 9a0d150c1bdc414288bd732bfc6e3fbe [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9a0d150c1bdc414288bd732bfc6e3fbe" member_type: VOTER }
I20260812 06:17:25.237259 17265 leader_election.cc:304] T 00000000000000000000000000000000 P 9a0d150c1bdc414288bd732bfc6e3fbe [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: 9a0d150c1bdc414288bd732bfc6e3fbe; no voters: 
I20260812 06:17:25.237618 17265 leader_election.cc:290] T 00000000000000000000000000000000 P 9a0d150c1bdc414288bd732bfc6e3fbe [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:25.237763 17271 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 9a0d150c1bdc414288bd732bfc6e3fbe [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:25.238021 17271 raft_consensus.cc:697] T 00000000000000000000000000000000 P 9a0d150c1bdc414288bd732bfc6e3fbe [term 1 LEADER]: Becoming Leader. State: Replica: 9a0d150c1bdc414288bd732bfc6e3fbe, State: Running, Role: LEADER
I20260812 06:17:25.238467 17271 consensus_queue.cc:237] T 00000000000000000000000000000000 P 9a0d150c1bdc414288bd732bfc6e3fbe [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: "9a0d150c1bdc414288bd732bfc6e3fbe" member_type: VOTER }
I20260812 06:17:25.238539 17265 sys_catalog.cc:565] T 00000000000000000000000000000000 P 9a0d150c1bdc414288bd732bfc6e3fbe [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:25.240231 17274 sys_catalog.cc:455] T 00000000000000000000000000000000 P 9a0d150c1bdc414288bd732bfc6e3fbe [sys.catalog]: SysCatalogTable state changed. Reason: New leader 9a0d150c1bdc414288bd732bfc6e3fbe. Latest consensus state: current_term: 1 leader_uuid: "9a0d150c1bdc414288bd732bfc6e3fbe" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9a0d150c1bdc414288bd732bfc6e3fbe" member_type: VOTER } }
I20260812 06:17:25.240352 17274 sys_catalog.cc:458] T 00000000000000000000000000000000 P 9a0d150c1bdc414288bd732bfc6e3fbe [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:25.240677 17272 sys_catalog.cc:455] T 00000000000000000000000000000000 P 9a0d150c1bdc414288bd732bfc6e3fbe [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "9a0d150c1bdc414288bd732bfc6e3fbe" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9a0d150c1bdc414288bd732bfc6e3fbe" member_type: VOTER } }
I20260812 06:17:25.240767 17272 sys_catalog.cc:458] T 00000000000000000000000000000000 P 9a0d150c1bdc414288bd732bfc6e3fbe [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:25.240854 17139 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:17:25.242753 17297 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 9a0d150c1bdc414288bd732bfc6e3fbe: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:17:25.242849 17297 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:17:25.242913 17294 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:25.243598 17294 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:25.247870 17294 catalog_manager.cc:1383] Generated new cluster ID: e5e320fbce614b238b2d4701c1d35c6b
I20260812 06:17:25.247937 17294 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:25.256444 17294 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:25.257599 17294 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:25.270902 17294 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 9a0d150c1bdc414288bd732bfc6e3fbe: Generated new TSK 0
I20260812 06:17:25.271639 17294 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:25.273270 17139 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:25.275950 17302 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:25.275966 17305 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:25.275974 17308 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:25.276520 17139 server_base.cc:1061] running on GCE node
I20260812 06:17:25.276695 17139 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:25.276743 17139 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:25.276759 17139 hybrid_clock.cc:648] HybridClock initialized: now 1786515445276759 us; error 0 us; skew 500 ppm
I20260812 06:17:25.277757 17139 webserver.cc:533] Webserver started at http://127.16.188.193:32979/ using document root <none> and password file <none>
I20260812 06:17:25.277936 17139 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:25.277992 17139 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:25.278087 17139 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:25.278487 17139 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445158667-17139-0/minicluster-data/ts-0-root/instance:
uuid: "360a4414084e40b8b5670e48715464ba"
format_stamp: "Formatted at 2026-08-12 06:17:25 on dist-test-slave-j2vl"
I20260812 06:17:25.279959 17139 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:25.280977 17318 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:25.281260 17139 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:25.281368 17139 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445158667-17139-0/minicluster-data/ts-0-root
uuid: "360a4414084e40b8b5670e48715464ba"
format_stamp: "Formatted at 2026-08-12 06:17:25 on dist-test-slave-j2vl"
I20260812 06:17:25.281469 17139 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445158667-17139-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445158667-17139-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445158667-17139-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:25.291849 17139 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:25.292310 17139 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:25.292855 17139 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:25.293859 17139 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:25.293926 17139 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:25.293993 17139 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:25.294047 17139 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:25.300999 17139 rpc_server.cc:307] RPC server started. Bound to: 127.16.188.193:41283
I20260812 06:17:25.301031 17428 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.16.188.193:41283 every 8 connection(s)
I20260812 06:17:25.315438 17429 heartbeater.cc:344] Connected to a master server at 127.16.188.254:40221
I20260812 06:17:25.315696 17429 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:25.316126 17429 heartbeater.cc:507] Master 127.16.188.254:40221 requested a full tablet report, sending...
I20260812 06:17:25.317631 17200 ts_manager.cc:194] Registered new tserver with Master: 360a4414084e40b8b5670e48715464ba (127.16.188.193:41283)
I20260812 06:17:25.318476 17139 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.016734603s
I20260812 06:17:25.319589 17200 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:49522
I20260812 06:17:25.328094 17200 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:49536:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:17:25.342960 17358 tablet_service.cc:1511] Processing CreateTablet for tablet 841a2d9723ac4e6b9a1682c1915f21da (DEFAULT_TABLE table=heavy-update-compaction-test [id=8e6411bf230f446c92fee16db214e4c6]), partition=
I20260812 06:17:25.343482 17358 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 841a2d9723ac4e6b9a1682c1915f21da. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:25.346076 17452 tablet_bootstrap.cc:492] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba: Bootstrap starting.
I20260812 06:17:25.347033 17452 tablet_bootstrap.cc:654] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:25.348378 17452 tablet_bootstrap.cc:492] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba: No bootstrap required, opened a new log
I20260812 06:17:25.348465 17452 ts_tablet_manager.cc:1403] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:25.348995 17452 raft_consensus.cc:359] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "360a4414084e40b8b5670e48715464ba" member_type: VOTER last_known_addr { host: "127.16.188.193" port: 41283 } }
I20260812 06:17:25.349148 17452 raft_consensus.cc:385] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:25.349242 17452 raft_consensus.cc:740] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 360a4414084e40b8b5670e48715464ba, State: Initialized, Role: FOLLOWER
I20260812 06:17:25.349478 17452 consensus_queue.cc:260] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba [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: "360a4414084e40b8b5670e48715464ba" member_type: VOTER last_known_addr { host: "127.16.188.193" port: 41283 } }
I20260812 06:17:25.349617 17452 raft_consensus.cc:399] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:25.349707 17452 raft_consensus.cc:493] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:25.349771 17452 raft_consensus.cc:3060] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:25.350526 17452 raft_consensus.cc:515] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "360a4414084e40b8b5670e48715464ba" member_type: VOTER last_known_addr { host: "127.16.188.193" port: 41283 } }
I20260812 06:17:25.350677 17452 leader_election.cc:304] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba [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: 360a4414084e40b8b5670e48715464ba; no voters: 
I20260812 06:17:25.350934 17452 leader_election.cc:290] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:25.351032 17454 raft_consensus.cc:2804] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:25.351295 17452 ts_tablet_manager.cc:1434] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:17:25.351539 17429 heartbeater.cc:499] Master 127.16.188.254:40221 was elected leader, sending a full tablet report...
I20260812 06:17:25.351631 17454 raft_consensus.cc:697] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba [term 1 LEADER]: Becoming Leader. State: Replica: 360a4414084e40b8b5670e48715464ba, State: Running, Role: LEADER
I20260812 06:17:25.351812 17454 consensus_queue.cc:237] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba [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: "360a4414084e40b8b5670e48715464ba" member_type: VOTER last_known_addr { host: "127.16.188.193" port: 41283 } }
I20260812 06:17:25.354656 17200 catalog_manager.cc:5719] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba reported cstate change: term changed from 0 to 1, leader changed from <none> to 360a4414084e40b8b5670e48715464ba (127.16.188.193). New cstate: current_term: 1 leader_uuid: "360a4414084e40b8b5670e48715464ba" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "360a4414084e40b8b5670e48715464ba" member_type: VOTER last_known_addr { host: "127.16.188.193" port: 41283 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:25.416796 17139 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.055s	user 0.017s	sys 0.009s
I20260812 06:17:25.552152 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling FlushMRSOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=19.054940
I20260812 06:17:25.730206 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: FlushMRSOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.178s	user 0.104s	sys 0.067s Metrics: {"bytes_written":13538208,"cfile_init":1,"compiler_manager_pool.queue_time_us":237,"delete_count":0,"dirs.queue_time_us":69,"dirs.run_cpu_time_us":247,"dirs.run_wall_time_us":830,"drs_written":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4,"lbm_write_time_us":45191,"lbm_writes_lt_1ms":787,"mutex_wait_us":1592,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":134528,"thread_start_us":140,"threads_started":1,"update_count":1650}
I20260812 06:17:25.731613 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=2.188937
I20260812 06:17:25.745896 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.014s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4143687,"delete_count":0,"lbm_write_time_us":5568,"lbm_writes_lt_1ms":104,"reinsert_count":0,"update_count":505}
I20260812 06:17:25.746446 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling LogGCOp(841a2d9723ac4e6b9a1682c1915f21da): free 20743831 bytes of WAL
I20260812 06:17:25.746805 17326 log_reader.cc:385] T 841a2d9723ac4e6b9a1682c1915f21da: removed 2 log segments from log reader
I20260812 06:17:25.746922 17326 log.cc:1079] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/841a2d9723ac4e6b9a1682c1915f21da/wal-000000001 (ops 1-6)
I20260812 06:17:25.747025 17326 log.cc:1079] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/841a2d9723ac4e6b9a1682c1915f21da/wal-000000002 (ops 7-11)
I20260812 06:17:25.753176 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: LogGCOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.007s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:17:25.753561 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling UndoDeltaBlockGCOp(841a2d9723ac4e6b9a1682c1915f21da): 16411396 bytes on disk
I20260812 06:17:25.754184 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: UndoDeltaBlockGCOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4}
I20260812 06:17:25.754671 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=1.196750
I20260812 06:17:25.766223 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.011s	user 0.010s	sys 0.001s Metrics: {"bytes_written":2830880,"delete_count":0,"lbm_write_time_us":4224,"lbm_writes_lt_1ms":72,"reinsert_count":0,"update_count":345}
I20260812 06:17:25.766717 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling MajorDeltaCompactionOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=1.000000
I20260812 06:17:25.936512 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: MajorDeltaCompactionOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.170s	user 0.137s	sys 0.032s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774775,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1091,"lbm_read_time_us":11746,"lbm_reads_lt_1ms":569,"lbm_write_time_us":29121,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"thread_start_us":329,"threads_started":5,"update_count":2500}
I20260812 06:17:25.937130 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=10.126437
I20260812 06:17:25.977939 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.041s	user 0.037s	sys 0.003s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17766,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:25.978533 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=2.188937
I20260812 06:17:25.991027 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4337,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:25.991454 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling MajorDeltaCompactionOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=1.000000
I20260812 06:17:26.116992 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: MajorDeltaCompactionOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.125s	user 0.107s	sys 0.014s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":759,"lbm_read_time_us":8622,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21922,"lbm_writes_lt_1ms":443,"mutex_wait_us":306,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:26.117564 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=10.126437
I20260812 06:17:26.154142 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.036s	user 0.022s	sys 0.013s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":15557,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:26.154695 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=2.188937
I20260812 06:17:26.169711 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5548,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:26.170269 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling MajorDeltaCompactionOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=1.000000
I20260812 06:17:26.298588 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: MajorDeltaCompactionOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.128s	user 0.103s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":692,"lbm_read_time_us":8173,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26628,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:26.299214 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=10.126437
I20260812 06:17:26.347388 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.048s	user 0.018s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13938,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:26.347836 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=2.188937
I20260812 06:17:26.358103 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3879,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:26.358930 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling MajorDeltaCompactionOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=1.000000
I20260812 06:17:26.487692 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: MajorDeltaCompactionOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.128s	user 0.108s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1280,"lbm_read_time_us":9239,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22084,"lbm_writes_lt_1ms":443,"mutex_wait_us":355,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:17:26.488281 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=10.126437
I20260812 06:17:26.536180 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.048s	user 0.014s	sys 0.026s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15855,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:26.536648 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=2.188937
I20260812 06:17:26.547118 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4139,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:26.547590 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling MajorDeltaCompactionOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=1.000000
I20260812 06:17:26.694046 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: MajorDeltaCompactionOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.146s	user 0.100s	sys 0.046s 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":1525,"lbm_read_time_us":10766,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23787,"lbm_writes_lt_1ms":443,"mutex_wait_us":534,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2000}
I20260812 06:17:26.694737 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=10.126437
I20260812 06:17:26.738962 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.044s	user 0.024s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14366,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:26.739475 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=2.188937
I20260812 06:17:26.750157 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.010s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4102,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:26.750715 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling MajorDeltaCompactionOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=1.000000
I20260812 06:17:26.880739 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: MajorDeltaCompactionOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.130s	user 0.098s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":288,"lbm_read_time_us":7660,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26683,"lbm_writes_lt_1ms":443,"mutex_wait_us":32,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:17:26.881481 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=10.126437
I20260812 06:17:26.926172 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.045s	user 0.023s	sys 0.012s Metrics: {"bytes_written":12307579,"delete_count":0,"lbm_write_time_us":15838,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:26.926744 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=2.188937
I20260812 06:17:26.937536 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4101,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:26.938246 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling FlushMRSOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=1.000000
I20260812 06:17:26.967514 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: FlushMRSOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.029s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":243,"dirs.run_wall_time_us":1589,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1473,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:26.968282 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling LogGCOp(841a2d9723ac4e6b9a1682c1915f21da): free 120553449 bytes of WAL
I20260812 06:17:26.968518 17326 log_reader.cc:385] T 841a2d9723ac4e6b9a1682c1915f21da: removed 12 log segments from log reader
I20260812 06:17:26.968564 17326 log.cc:1079] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/841a2d9723ac4e6b9a1682c1915f21da/wal-000000003 (ops 12-16)
I20260812 06:17:26.968592 17326 log.cc:1079] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/841a2d9723ac4e6b9a1682c1915f21da/wal-000000004 (ops 17-21)
I20260812 06:17:26.968657 17326 log.cc:1079] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/841a2d9723ac4e6b9a1682c1915f21da/wal-000000005 (ops 22-26)
I20260812 06:17:26.968698 17326 log.cc:1079] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/841a2d9723ac4e6b9a1682c1915f21da/wal-000000006 (ops 27-30)
I20260812 06:17:26.968739 17326 log.cc:1079] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/841a2d9723ac4e6b9a1682c1915f21da/wal-000000007 (ops 31-35)
I20260812 06:17:26.968803 17326 log.cc:1079] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/841a2d9723ac4e6b9a1682c1915f21da/wal-000000008 (ops 36-40)
I20260812 06:17:26.968840 17326 log.cc:1079] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/841a2d9723ac4e6b9a1682c1915f21da/wal-000000009 (ops 41-44)
I20260812 06:17:26.968883 17326 log.cc:1079] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/841a2d9723ac4e6b9a1682c1915f21da/wal-000000010 (ops 45-49)
I20260812 06:17:26.968917 17326 log.cc:1079] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/841a2d9723ac4e6b9a1682c1915f21da/wal-000000011 (ops 50-54)
I20260812 06:17:26.968966 17326 log.cc:1079] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/841a2d9723ac4e6b9a1682c1915f21da/wal-000000012 (ops 55-59)
I20260812 06:17:26.969009 17326 log.cc:1079] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/841a2d9723ac4e6b9a1682c1915f21da/wal-000000013 (ops 60-64)
I20260812 06:17:26.969048 17326 log.cc:1079] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/841a2d9723ac4e6b9a1682c1915f21da/wal-000000014 (ops 65-69)
I20260812 06:17:26.994213 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: LogGCOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.026s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:17:26.994721 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=4.173312
I20260812 06:17:27.008962 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.014s	user 0.007s	sys 0.005s Metrics: {"bytes_written":5538513,"delete_count":0,"lbm_write_time_us":5697,"lbm_writes_lt_1ms":138,"reinsert_count":0,"update_count":675}
I20260812 06:17:27.009517 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=1.196750
I20260812 06:17:27.019282 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.010s	user 0.003s	sys 0.005s Metrics: {"bytes_written":2666779,"delete_count":0,"lbm_write_time_us":3228,"lbm_writes_lt_1ms":68,"reinsert_count":0,"update_count":325}
I20260812 06:17:27.019749 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling MajorDeltaCompactionOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=1.000000
I20260812 06:17:27.188067 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: MajorDeltaCompactionOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.168s	user 0.139s	sys 0.024s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877396,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":920,"lbm_read_time_us":10833,"lbm_reads_lt_1ms":666,"lbm_write_time_us":34530,"lbm_writes_lt_1ms":643,"mutex_wait_us":45,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":10880,"thread_start_us":77,"threads_started":1,"update_count":3000}
I20260812 06:17:27.189256 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling UndoDeltaBlockGCOp(841a2d9723ac4e6b9a1682c1915f21da): 462 bytes on disk
I20260812 06:17:27.189819 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: UndoDeltaBlockGCOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":92,"lbm_reads_lt_1ms":4}
I20260812 06:17:27.190284 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=14.095187
I20260812 06:17:27.238292 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.048s	user 0.034s	sys 0.013s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":20365,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:27.238739 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=2.188937
I20260812 06:17:27.252281 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.013s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5268,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:27.252912 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling MajorDeltaCompactionOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=1.000000
I20260812 06:17:27.400184 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: MajorDeltaCompactionOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.147s	user 0.124s	sys 0.017s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":263,"lbm_read_time_us":9620,"lbm_reads_lt_1ms":564,"lbm_write_time_us":28786,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:27.400724 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=14.095187
I20260812 06:17:27.464856 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.064s	user 0.032s	sys 0.028s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":30692,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:27.465479 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=2.188937
I20260812 06:17:27.476426 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.011s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3834,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:27.477084 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling MajorDeltaCompactionOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=1.000000
I20260812 06:17:27.645744 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: MajorDeltaCompactionOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.168s	user 0.116s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":823,"lbm_read_time_us":11510,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28613,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":75904,"update_count":2500}
I20260812 06:17:27.646351 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=14.095187
I20260812 06:17:27.691227 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.045s	user 0.023s	sys 0.020s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":19678,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:27.691689 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling MajorDeltaCompactionOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=1.000000
I20260812 06:17:27.827507 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: MajorDeltaCompactionOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.136s	user 0.075s	sys 0.056s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672156,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":806,"lbm_read_time_us":8671,"lbm_reads_lt_1ms":467,"lbm_write_time_us":22755,"lbm_writes_lt_1ms":443,"mutex_wait_us":393,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2000}
I20260812 06:17:27.828090 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=11.118625
I20260812 06:17:27.864069 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.036s	user 0.030s	sys 0.003s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14955,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:27.864987 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=2.188937
I20260812 06:17:27.879824 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.015s	user 0.003s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4954,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:27.880321 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling MajorDeltaCompactionOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=1.000000
I20260812 06:17:28.005237 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: MajorDeltaCompactionOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.125s	user 0.096s	sys 0.028s 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":140,"lbm_read_time_us":8252,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23151,"lbm_writes_lt_1ms":443,"mutex_wait_us":36,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6656,"update_count":2000}
I20260812 06:17:28.005930 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=10.126437
I20260812 06:17:28.040877 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.035s	user 0.019s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14770,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:28.041621 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=2.188937
I20260812 06:17:28.060173 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.018s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5908,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:28.060688 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling MajorDeltaCompactionOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=1.000000
I20260812 06:17:28.182976 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: MajorDeltaCompactionOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.122s	user 0.094s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":788,"lbm_read_time_us":7316,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23090,"lbm_writes_lt_1ms":443,"mutex_wait_us":45,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:28.183614 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=11.118625
I20260812 06:17:28.218047 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.034s	user 0.022s	sys 0.011s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":15043,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:28.218516 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=2.188937
I20260812 06:17:28.232813 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.014s	user 0.004s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5645,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:28.233279 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling FlushMRSOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=1.000000
I20260812 06:17:28.258388 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: FlushMRSOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.025s	user 0.023s	sys 0.001s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":309,"dirs.run_wall_time_us":1366,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1756,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:28.259073 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling LogGCOp(841a2d9723ac4e6b9a1682c1915f21da): free 112692378 bytes of WAL
I20260812 06:17:28.259299 17326 log_reader.cc:385] T 841a2d9723ac4e6b9a1682c1915f21da: removed 11 log segments from log reader
I20260812 06:17:28.259346 17326 log.cc:1079] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/841a2d9723ac4e6b9a1682c1915f21da/wal-000000015 (ops 70-74)
I20260812 06:17:28.259382 17326 log.cc:1079] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/841a2d9723ac4e6b9a1682c1915f21da/wal-000000016 (ops 75-79)
I20260812 06:17:28.259449 17326 log.cc:1079] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/841a2d9723ac4e6b9a1682c1915f21da/wal-000000017 (ops 80-84)
I20260812 06:17:28.259483 17326 log.cc:1079] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/841a2d9723ac4e6b9a1682c1915f21da/wal-000000018 (ops 85-89)
I20260812 06:17:28.259524 17326 log.cc:1079] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/841a2d9723ac4e6b9a1682c1915f21da/wal-000000019 (ops 90-94)
I20260812 06:17:28.259552 17326 log.cc:1079] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/841a2d9723ac4e6b9a1682c1915f21da/wal-000000020 (ops 95-99)
I20260812 06:17:28.259594 17326 log.cc:1079] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/841a2d9723ac4e6b9a1682c1915f21da/wal-000000021 (ops 100-104)
I20260812 06:17:28.259635 17326 log.cc:1079] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/841a2d9723ac4e6b9a1682c1915f21da/wal-000000022 (ops 105-109)
I20260812 06:17:28.259675 17326 log.cc:1079] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/841a2d9723ac4e6b9a1682c1915f21da/wal-000000023 (ops 110-114)
I20260812 06:17:28.259716 17326 log.cc:1079] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/841a2d9723ac4e6b9a1682c1915f21da/wal-000000024 (ops 115-119)
I20260812 06:17:28.259756 17326 log.cc:1079] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/841a2d9723ac4e6b9a1682c1915f21da/wal-000000025 (ops 120-124)
I20260812 06:17:28.283557 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: LogGCOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.024s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:17:28.283981 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=3.181125
I20260812 06:17:28.295646 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4618,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:28.296066 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling UndoDeltaBlockGCOp(841a2d9723ac4e6b9a1682c1915f21da): 447 bytes on disk
I20260812 06:17:28.296446 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: UndoDeltaBlockGCOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4}
I20260812 06:17:28.296928 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=2.188937
I20260812 06:17:28.306618 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3696,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:28.307027 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling MajorDeltaCompactionOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=1.000000
I20260812 06:17:28.481258 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: MajorDeltaCompactionOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.174s	user 0.135s	sys 0.036s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877321,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":883,"lbm_read_time_us":12098,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33486,"lbm_writes_lt_1ms":643,"mutex_wait_us":52,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":10368,"thread_start_us":91,"threads_started":1,"update_count":3000}
I20260812 06:17:28.482018 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=14.095187
I20260812 06:17:28.534016 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.052s	user 0.030s	sys 0.016s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20236,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:28.534497 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=2.188937
I20260812 06:17:28.546259 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.012s	user 0.005s	sys 0.006s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4281,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:28.546761 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling MajorDeltaCompactionOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=1.000000
I20260812 06:17:28.706367 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: MajorDeltaCompactionOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.159s	user 0.110s	sys 0.040s 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":159,"lbm_read_time_us":10262,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30278,"lbm_writes_lt_1ms":543,"mutex_wait_us":1,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:17:28.707052 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=14.095187
I20260812 06:17:28.756953 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.050s	user 0.032s	sys 0.012s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":21095,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:28.757642 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling MajorDeltaCompactionOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=1.000000
I20260812 06:17:28.907452 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: MajorDeltaCompactionOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.150s	user 0.074s	sys 0.072s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672156,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":521,"lbm_read_time_us":10512,"lbm_reads_lt_1ms":463,"lbm_write_time_us":24774,"lbm_writes_lt_1ms":443,"mutex_wait_us":233,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3840,"update_count":2000}
I20260812 06:17:28.908018 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=11.118625
I20260812 06:17:28.945681 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.037s	user 0.017s	sys 0.020s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15600,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:28.946368 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=2.188937
I20260812 06:17:28.958063 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4167,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:28.958535 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling MajorDeltaCompactionOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=1.000000
I20260812 06:17:29.092259 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: MajorDeltaCompactionOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.134s	user 0.109s	sys 0.024s 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":174,"lbm_read_time_us":8342,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26148,"lbm_writes_lt_1ms":443,"mutex_wait_us":93,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2000}
I20260812 06:17:29.092965 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=10.126437
I20260812 06:17:29.133829 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.041s	user 0.023s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15094,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:29.134281 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=2.188937
I20260812 06:17:29.145403 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4057,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:29.146011 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling MajorDeltaCompactionOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=1.000000
I20260812 06:17:29.275128 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: MajorDeltaCompactionOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.129s	user 0.096s	sys 0.032s 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":326,"lbm_read_time_us":9649,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22515,"lbm_writes_lt_1ms":443,"mutex_wait_us":48,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12288,"update_count":2000}
I20260812 06:17:29.275816 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=10.126437
I20260812 06:17:29.319481 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.043s	user 0.016s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15089,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:29.320013 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=2.188937
I20260812 06:17:29.331427 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.011s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3971,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:29.331972 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling MajorDeltaCompactionOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=1.000000
I20260812 06:17:29.453207 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: MajorDeltaCompactionOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.121s	user 0.108s	sys 0.012s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":731,"lbm_read_time_us":9158,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21228,"lbm_writes_lt_1ms":443,"mutex_wait_us":63,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":2000}
I20260812 06:17:29.453902 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=10.126437
I20260812 06:17:29.501415 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.047s	user 0.020s	sys 0.027s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18542,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:29.502029 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=2.188937
I20260812 06:17:29.514129 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.012s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4774,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:29.514616 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling MajorDeltaCompactionOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=1.000000
I20260812 06:17:29.669209 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: MajorDeltaCompactionOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.153s	user 0.117s	sys 0.036s 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":1074,"lbm_read_time_us":10640,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26171,"lbm_writes_lt_1ms":443,"mutex_wait_us":214,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2000}
I20260812 06:17:29.670055 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=10.126437
I20260812 06:17:29.703684 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.033s	user 0.019s	sys 0.011s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14928,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:29.704180 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=2.188937
I20260812 06:17:29.719175 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5612,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:29.719820 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling FlushMRSOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=1.000000
I20260812 06:17:29.753173 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: FlushMRSOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.033s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1275445,"cfile_init":1,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":188,"dirs.run_wall_time_us":1254,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1652,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:29.753912 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling LogGCOp(841a2d9723ac4e6b9a1682c1915f21da): free 128867704 bytes of WAL
I20260812 06:17:29.754145 17326 log_reader.cc:385] T 841a2d9723ac4e6b9a1682c1915f21da: removed 13 log segments from log reader
I20260812 06:17:29.754191 17326 log.cc:1079] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/841a2d9723ac4e6b9a1682c1915f21da/wal-000000026 (ops 125-129)
I20260812 06:17:29.754220 17326 log.cc:1079] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/841a2d9723ac4e6b9a1682c1915f21da/wal-000000027 (ops 130-134)
I20260812 06:17:29.754283 17326 log.cc:1079] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/841a2d9723ac4e6b9a1682c1915f21da/wal-000000028 (ops 135-138)
I20260812 06:17:29.754326 17326 log.cc:1079] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/841a2d9723ac4e6b9a1682c1915f21da/wal-000000029 (ops 139-143)
I20260812 06:17:29.754370 17326 log.cc:1079] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/841a2d9723ac4e6b9a1682c1915f21da/wal-000000030 (ops 144-148)
I20260812 06:17:29.754413 17326 log.cc:1079] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/841a2d9723ac4e6b9a1682c1915f21da/wal-000000031 (ops 149-152)
I20260812 06:17:29.754447 17326 log.cc:1079] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/841a2d9723ac4e6b9a1682c1915f21da/wal-000000032 (ops 153-157)
I20260812 06:17:29.754489 17326 log.cc:1079] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/841a2d9723ac4e6b9a1682c1915f21da/wal-000000033 (ops 158-162)
I20260812 06:17:29.754523 17326 log.cc:1079] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/841a2d9723ac4e6b9a1682c1915f21da/wal-000000034 (ops 163-166)
I20260812 06:17:29.754562 17326 log.cc:1079] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/841a2d9723ac4e6b9a1682c1915f21da/wal-000000035 (ops 167-171)
I20260812 06:17:29.754601 17326 log.cc:1079] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/841a2d9723ac4e6b9a1682c1915f21da/wal-000000036 (ops 172-176)
I20260812 06:17:29.754640 17326 log.cc:1079] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/841a2d9723ac4e6b9a1682c1915f21da/wal-000000037 (ops 177-181)
I20260812 06:17:29.754678 17326 log.cc:1079] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/841a2d9723ac4e6b9a1682c1915f21da/wal-000000038 (ops 182-186)
I20260812 06:17:29.783730 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: LogGCOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.030s	user 0.005s	sys 0.023s Metrics: {}
I20260812 06:17:29.784169 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling UndoDeltaBlockGCOp(841a2d9723ac4e6b9a1682c1915f21da): 482 bytes on disk
I20260812 06:17:29.784629 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: UndoDeltaBlockGCOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4}
I20260812 06:17:29.785300 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=3.181125
I20260812 06:17:29.802887 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.017s	user 0.007s	sys 0.009s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":7164,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:29.803349 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=2.188937
I20260812 06:17:29.822196 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.019s	user 0.004s	sys 0.013s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3620,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:29.822803 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling MajorDeltaCompactionOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=1.000000
I20260812 06:17:30.017988 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: MajorDeltaCompactionOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.195s	user 0.134s	sys 0.061s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877330,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":210,"lbm_read_time_us":13731,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33618,"lbm_writes_lt_1ms":643,"mutex_wait_us":21,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7552,"thread_start_us":73,"threads_started":1,"update_count":3000}
I20260812 06:17:30.020577 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=14.095187
I20260812 06:17:30.080370 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.060s	user 0.030s	sys 0.027s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21913,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:30.080996 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=2.188937
I20260812 06:17:30.098116 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: FlushDeltaMemStoresOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.017s	user 0.013s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6664,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:30.098703 17430 maintenance_manager.cc:419] P 360a4414084e40b8b5670e48715464ba: Scheduling MajorDeltaCompactionOp(841a2d9723ac4e6b9a1682c1915f21da): perf score=1.000000
I20260812 06:17:30.148921 17139 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.732s	user 1.729s	sys 0.175s
I20260812 06:17:30.222640 17139 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.073s	user 0.002s	sys 0.000s
I20260812 06:17:30.223272 17139 tablet_server.cc:179] TabletServer@127.16.188.193:0 shutting down...
I20260812 06:17:30.254567 17326 maintenance_manager.cc:643] P 360a4414084e40b8b5670e48715464ba: MajorDeltaCompactionOp(841a2d9723ac4e6b9a1682c1915f21da) complete. Timing: real 0.156s	user 0.097s	sys 0.057s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":297,"lbm_read_time_us":11719,"lbm_reads_lt_1ms":568,"lbm_write_time_us":26202,"lbm_writes_lt_1ms":543,"mutex_wait_us":48,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:17:30.255265 17139 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:30.255645 17139 tablet_replica.cc:333] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba: stopping tablet replica
I20260812 06:17:30.255897 17139 raft_consensus.cc:2243] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:30.256139 17139 raft_consensus.cc:2272] T 841a2d9723ac4e6b9a1682c1915f21da P 360a4414084e40b8b5670e48715464ba [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:30.271998 17139 tablet_server.cc:196] TabletServer@127.16.188.193:0 shutdown complete.
I20260812 06:17:30.301403 17139 master.cc:562] Master@127.16.188.254:40221 shutting down...
I20260812 06:17:30.305140 17139 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 9a0d150c1bdc414288bd732bfc6e3fbe [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:30.305297 17139 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 9a0d150c1bdc414288bd732bfc6e3fbe [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:30.305404 17139 tablet_replica.cc:333] T 00000000000000000000000000000000 P 9a0d150c1bdc414288bd732bfc6e3fbe: stopping tablet replica
I20260812 06:17:30.317734 17139 master.cc:584] Master@127.16.188.254:40221 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5236 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:30.417899 17139 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.16.188.254:39677
I20260812 06:17:30.418275 17139 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:30.420351 17487 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:30.420426 17139 server_base.cc:1061] running on GCE node
W20260812 06:17:30.420452 17493 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:30.420362 17489 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:30.420717 17139 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:30.420760 17139 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:30.420775 17139 hybrid_clock.cc:648] HybridClock initialized: now 1786515450420776 us; error 0 us; skew 500 ppm
I20260812 06:17:30.421697 17139 webserver.cc:533] Webserver started at http://127.16.188.254:34693/ using document root <none> and password file <none>
I20260812 06:17:30.421876 17139 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:30.421962 17139 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:30.422049 17139 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:30.422480 17139 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445158667-17139-0/minicluster-data/master-0-root/instance:
uuid: "c5da48cc5eac45649f5882293d5f4e46"
format_stamp: "Formatted at 2026-08-12 06:17:30 on dist-test-slave-j2vl"
I20260812 06:17:30.424000 17139 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:30.424908 17499 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:30.425124 17139 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:30.425217 17139 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445158667-17139-0/minicluster-data/master-0-root
uuid: "c5da48cc5eac45649f5882293d5f4e46"
format_stamp: "Formatted at 2026-08-12 06:17:30 on dist-test-slave-j2vl"
I20260812 06:17:30.425305 17139 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445158667-17139-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445158667-17139-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445158667-17139-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:30.436920 17139 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:30.437288 17139 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:30.441582 17139 rpc_server.cc:307] RPC server started. Bound to: 127.16.188.254:39677
I20260812 06:17:30.443234 17597 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.16.188.254:39677 every 8 connection(s)
I20260812 06:17:30.443703 17598 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:30.445477 17598 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P c5da48cc5eac45649f5882293d5f4e46: Bootstrap starting.
I20260812 06:17:30.446208 17598 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P c5da48cc5eac45649f5882293d5f4e46: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:30.447158 17598 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P c5da48cc5eac45649f5882293d5f4e46: No bootstrap required, opened a new log
I20260812 06:17:30.447559 17598 raft_consensus.cc:359] T 00000000000000000000000000000000 P c5da48cc5eac45649f5882293d5f4e46 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c5da48cc5eac45649f5882293d5f4e46" member_type: VOTER }
I20260812 06:17:30.447644 17598 raft_consensus.cc:385] T 00000000000000000000000000000000 P c5da48cc5eac45649f5882293d5f4e46 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:30.447695 17598 raft_consensus.cc:740] T 00000000000000000000000000000000 P c5da48cc5eac45649f5882293d5f4e46 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: c5da48cc5eac45649f5882293d5f4e46, State: Initialized, Role: FOLLOWER
I20260812 06:17:30.447867 17598 consensus_queue.cc:260] T 00000000000000000000000000000000 P c5da48cc5eac45649f5882293d5f4e46 [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: "c5da48cc5eac45649f5882293d5f4e46" member_type: VOTER }
I20260812 06:17:30.447939 17598 raft_consensus.cc:399] T 00000000000000000000000000000000 P c5da48cc5eac45649f5882293d5f4e46 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:30.447992 17598 raft_consensus.cc:493] T 00000000000000000000000000000000 P c5da48cc5eac45649f5882293d5f4e46 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:30.448055 17598 raft_consensus.cc:3060] T 00000000000000000000000000000000 P c5da48cc5eac45649f5882293d5f4e46 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:30.448730 17598 raft_consensus.cc:515] T 00000000000000000000000000000000 P c5da48cc5eac45649f5882293d5f4e46 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c5da48cc5eac45649f5882293d5f4e46" member_type: VOTER }
I20260812 06:17:30.448843 17598 leader_election.cc:304] T 00000000000000000000000000000000 P c5da48cc5eac45649f5882293d5f4e46 [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: c5da48cc5eac45649f5882293d5f4e46; no voters: 
I20260812 06:17:30.449087 17598 leader_election.cc:290] T 00000000000000000000000000000000 P c5da48cc5eac45649f5882293d5f4e46 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:30.449203 17607 raft_consensus.cc:2804] T 00000000000000000000000000000000 P c5da48cc5eac45649f5882293d5f4e46 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:30.449487 17607 raft_consensus.cc:697] T 00000000000000000000000000000000 P c5da48cc5eac45649f5882293d5f4e46 [term 1 LEADER]: Becoming Leader. State: Replica: c5da48cc5eac45649f5882293d5f4e46, State: Running, Role: LEADER
I20260812 06:17:30.449522 17598 sys_catalog.cc:565] T 00000000000000000000000000000000 P c5da48cc5eac45649f5882293d5f4e46 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:30.449679 17607 consensus_queue.cc:237] T 00000000000000000000000000000000 P c5da48cc5eac45649f5882293d5f4e46 [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: "c5da48cc5eac45649f5882293d5f4e46" member_type: VOTER }
I20260812 06:17:30.450783 17611 sys_catalog.cc:455] T 00000000000000000000000000000000 P c5da48cc5eac45649f5882293d5f4e46 [sys.catalog]: SysCatalogTable state changed. Reason: New leader c5da48cc5eac45649f5882293d5f4e46. Latest consensus state: current_term: 1 leader_uuid: "c5da48cc5eac45649f5882293d5f4e46" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c5da48cc5eac45649f5882293d5f4e46" member_type: VOTER } }
I20260812 06:17:30.450897 17611 sys_catalog.cc:458] T 00000000000000000000000000000000 P c5da48cc5eac45649f5882293d5f4e46 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:30.451202 17621 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:30.451186 17608 sys_catalog.cc:455] T 00000000000000000000000000000000 P c5da48cc5eac45649f5882293d5f4e46 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "c5da48cc5eac45649f5882293d5f4e46" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c5da48cc5eac45649f5882293d5f4e46" member_type: VOTER } }
I20260812 06:17:30.451341 17608 sys_catalog.cc:458] T 00000000000000000000000000000000 P c5da48cc5eac45649f5882293d5f4e46 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:30.452121 17621 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:30.452457 17139 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:30.454228 17621 catalog_manager.cc:1383] Generated new cluster ID: 861c3b20bc0848be88f72419c87c7741
I20260812 06:17:30.454288 17621 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:30.458887 17621 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:30.459409 17621 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:30.466112 17621 catalog_manager.cc:6092] T 00000000000000000000000000000000 P c5da48cc5eac45649f5882293d5f4e46: Generated new TSK 0
I20260812 06:17:30.466305 17621 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:30.468685 17139 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:30.470788 17633 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:30.470842 17639 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:30.470852 17634 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:30.471892 17139 server_base.cc:1061] running on GCE node
I20260812 06:17:30.472064 17139 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:30.472100 17139 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:30.472115 17139 hybrid_clock.cc:648] HybridClock initialized: now 1786515450472115 us; error 0 us; skew 500 ppm
I20260812 06:17:30.472914 17139 webserver.cc:533] Webserver started at http://127.16.188.193:34309/ using document root <none> and password file <none>
I20260812 06:17:30.473042 17139 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:30.473080 17139 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:30.473129 17139 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:30.473536 17139 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445158667-17139-0/minicluster-data/ts-0-root/instance:
uuid: "190d05ce5600454f85031494090af0c1"
format_stamp: "Formatted at 2026-08-12 06:17:30 on dist-test-slave-j2vl"
I20260812 06:17:30.474886 17139 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:30.475736 17649 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:30.476030 17139 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:30.476094 17139 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445158667-17139-0/minicluster-data/ts-0-root
uuid: "190d05ce5600454f85031494090af0c1"
format_stamp: "Formatted at 2026-08-12 06:17:30 on dist-test-slave-j2vl"
I20260812 06:17:30.476182 17139 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445158667-17139-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445158667-17139-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445158667-17139-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:30.484278 17139 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:30.484598 17139 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:30.484876 17139 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:30.485319 17139 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:30.485409 17139 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:30.485464 17139 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:30.485515 17139 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:30.489740 17139 rpc_server.cc:307] RPC server started. Bound to: 127.16.188.193:39859
I20260812 06:17:30.490396 17764 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.16.188.193:39859 every 8 connection(s)
I20260812 06:17:30.498355 17766 heartbeater.cc:344] Connected to a master server at 127.16.188.254:39677
I20260812 06:17:30.498464 17766 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:30.498643 17766 heartbeater.cc:507] Master 127.16.188.254:39677 requested a full tablet report, sending...
I20260812 06:17:30.499249 17534 ts_manager.cc:194] Registered new tserver with Master: 190d05ce5600454f85031494090af0c1 (127.16.188.193:39859)
I20260812 06:17:30.499378 17139 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.008831627s
I20260812 06:17:30.500240 17534 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:48098
I20260812 06:17:30.506647 17534 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:48114:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:17:30.516146 17695 tablet_service.cc:1511] Processing CreateTablet for tablet f27414c4566440edaadd764d089e0810 (DEFAULT_TABLE table=heavy-update-compaction-test [id=32a31d59d33c47fcbdca2a52300a20f4]), partition=
I20260812 06:17:30.516443 17695 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet f27414c4566440edaadd764d089e0810. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:30.518436 17784 tablet_bootstrap.cc:492] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1: Bootstrap starting.
I20260812 06:17:30.519304 17784 tablet_bootstrap.cc:654] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:30.520475 17784 tablet_bootstrap.cc:492] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1: No bootstrap required, opened a new log
I20260812 06:17:30.520586 17784 ts_tablet_manager.cc:1403] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:17:30.520977 17784 raft_consensus.cc:359] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "190d05ce5600454f85031494090af0c1" member_type: VOTER last_known_addr { host: "127.16.188.193" port: 39859 } }
I20260812 06:17:30.521095 17784 raft_consensus.cc:385] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:30.521142 17784 raft_consensus.cc:740] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 190d05ce5600454f85031494090af0c1, State: Initialized, Role: FOLLOWER
I20260812 06:17:30.521276 17784 consensus_queue.cc:260] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1 [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: "190d05ce5600454f85031494090af0c1" member_type: VOTER last_known_addr { host: "127.16.188.193" port: 39859 } }
I20260812 06:17:30.521397 17784 raft_consensus.cc:399] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:30.521443 17784 raft_consensus.cc:493] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:30.521498 17784 raft_consensus.cc:3060] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:30.522179 17784 raft_consensus.cc:515] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "190d05ce5600454f85031494090af0c1" member_type: VOTER last_known_addr { host: "127.16.188.193" port: 39859 } }
I20260812 06:17:30.522328 17784 leader_election.cc:304] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1 [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: 190d05ce5600454f85031494090af0c1; no voters: 
I20260812 06:17:30.522548 17784 leader_election.cc:290] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:30.522653 17788 raft_consensus.cc:2804] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:30.522864 17788 raft_consensus.cc:697] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1 [term 1 LEADER]: Becoming Leader. State: Replica: 190d05ce5600454f85031494090af0c1, State: Running, Role: LEADER
I20260812 06:17:30.522919 17784 ts_tablet_manager.cc:1434] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:17:30.522940 17766 heartbeater.cc:499] Master 127.16.188.254:39677 was elected leader, sending a full tablet report...
I20260812 06:17:30.523028 17788 consensus_queue.cc:237] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1 [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: "190d05ce5600454f85031494090af0c1" member_type: VOTER last_known_addr { host: "127.16.188.193" port: 39859 } }
I20260812 06:17:30.524405 17534 catalog_manager.cc:5719] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1 reported cstate change: term changed from 0 to 1, leader changed from <none> to 190d05ce5600454f85031494090af0c1 (127.16.188.193). New cstate: current_term: 1 leader_uuid: "190d05ce5600454f85031494090af0c1" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "190d05ce5600454f85031494090af0c1" member_type: VOTER last_known_addr { host: "127.16.188.193" port: 39859 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:30.582012 17139 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.052s	user 0.014s	sys 0.008s
I20260812 06:17:30.741091 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling FlushMRSOp(f27414c4566440edaadd764d089e0810): perf score=19.054940
I20260812 06:17:30.881762 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: FlushMRSOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.140s	user 0.093s	sys 0.047s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":77,"dirs.run_cpu_time_us":218,"dirs.run_wall_time_us":827,"drs_written":1,"lbm_read_time_us":107,"lbm_reads_lt_1ms":4,"lbm_write_time_us":36807,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":2304,"update_count":1500}
I20260812 06:17:30.882469 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling LogGCOp(f27414c4566440edaadd764d089e0810): free 20290830 bytes of WAL
I20260812 06:17:30.882718 17656 log_reader.cc:385] T f27414c4566440edaadd764d089e0810: removed 2 log segments from log reader
I20260812 06:17:30.882762 17656 log.cc:1079] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/f27414c4566440edaadd764d089e0810/wal-000000001 (ops 1-6)
I20260812 06:17:30.882793 17656 log.cc:1079] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/f27414c4566440edaadd764d089e0810/wal-000000002 (ops 7-10)
I20260812 06:17:30.887231 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: LogGCOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.005s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:17:30.887672 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling UndoDeltaBlockGCOp(f27414c4566440edaadd764d089e0810): 16411396 bytes on disk
I20260812 06:17:30.888150 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: UndoDeltaBlockGCOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":77,"lbm_reads_lt_1ms":4}
I20260812 06:17:30.888599 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810): perf score=2.188937
I20260812 06:17:30.909031 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.020s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5533,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:30.909550 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810): perf score=1.000000
I20260812 06:17:30.918381 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.009s	user 0.003s	sys 0.001s Metrics: {"bytes_written":1271931,"delete_count":0,"lbm_write_time_us":1212,"lbm_writes_lt_1ms":34,"reinsert_count":0,"update_count":155}
I20260812 06:17:30.918768 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810): perf score=1.196750
I20260812 06:17:30.926808 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.008s	user 0.004s	sys 0.003s Metrics: {"bytes_written":2830880,"delete_count":0,"lbm_write_time_us":2937,"lbm_writes_lt_1ms":72,"reinsert_count":0,"update_count":345}
I20260812 06:17:30.927196 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling MajorDeltaCompactionOp(f27414c4566440edaadd764d089e0810): perf score=1.000000
I20260812 06:17:31.099334 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: MajorDeltaCompactionOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.172s	user 0.100s	sys 0.071s Metrics: {"cfile_cache_miss":534,"cfile_cache_miss_bytes":24774833,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1401,"lbm_read_time_us":11635,"lbm_reads_lt_1ms":570,"lbm_write_time_us":27895,"lbm_writes_lt_1ms":543,"mutex_wait_us":282,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7680,"thread_start_us":344,"threads_started":5,"update_count":2500}
I20260812 06:17:31.100035 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810): perf score=14.095187
I20260812 06:17:31.152351 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.052s	user 0.024s	sys 0.021s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20735,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:31.152856 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810): perf score=2.188937
I20260812 06:17:31.174372 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.021s	user 0.010s	sys 0.011s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4092,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:31.174841 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling MajorDeltaCompactionOp(f27414c4566440edaadd764d089e0810): perf score=1.000000
I20260812 06:17:31.363511 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: MajorDeltaCompactionOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.188s	user 0.131s	sys 0.058s 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":167,"lbm_read_time_us":13427,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30182,"lbm_writes_lt_1ms":543,"mutex_wait_us":41,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11648,"update_count":2500}
I20260812 06:17:31.364231 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810): perf score=14.095187
I20260812 06:17:31.413746 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.049s	user 0.033s	sys 0.015s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21029,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:31.414250 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810): perf score=2.188937
I20260812 06:17:31.426352 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.012s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4502,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:31.426883 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling MajorDeltaCompactionOp(f27414c4566440edaadd764d089e0810): perf score=1.000000
I20260812 06:17:31.600736 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: MajorDeltaCompactionOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.174s	user 0.110s	sys 0.060s 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":170,"lbm_read_time_us":10121,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28668,"lbm_writes_lt_1ms":543,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":92288,"update_count":2500}
I20260812 06:17:31.601365 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810): perf score=14.095187
I20260812 06:17:31.648336 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.047s	user 0.034s	sys 0.008s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19688,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:31.648880 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810): perf score=2.188937
I20260812 06:17:31.663805 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5632,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:31.664412 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling MajorDeltaCompactionOp(f27414c4566440edaadd764d089e0810): perf score=1.000000
I20260812 06:17:31.818138 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: MajorDeltaCompactionOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.153s	user 0.116s	sys 0.030s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":783,"lbm_read_time_us":10454,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27844,"lbm_writes_lt_1ms":543,"mutex_wait_us":350,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10624,"update_count":2500}
I20260812 06:17:31.818782 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810): perf score=14.095187
I20260812 06:17:31.868764 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.050s	user 0.024s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19084,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:31.869266 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810): perf score=2.188937
I20260812 06:17:31.879662 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4115,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:31.880122 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling MajorDeltaCompactionOp(f27414c4566440edaadd764d089e0810): perf score=1.000000
I20260812 06:17:32.036072 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: MajorDeltaCompactionOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.156s	user 0.123s	sys 0.024s 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":693,"lbm_read_time_us":9562,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27887,"lbm_writes_lt_1ms":543,"mutex_wait_us":70,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7552,"update_count":2500}
I20260812 06:17:32.036526 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810): perf score=14.095187
I20260812 06:17:32.082333 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.046s	user 0.023s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19331,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:32.082854 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810): perf score=2.188937
I20260812 06:17:32.093812 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3963,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:32.094370 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling FlushMRSOp(f27414c4566440edaadd764d089e0810): perf score=1.000000
I20260812 06:17:32.125489 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: FlushMRSOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.031s	user 0.027s	sys 0.004s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":64,"dirs.run_cpu_time_us":266,"dirs.run_wall_time_us":1214,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1984,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30,"spinlock_wait_cycles":2304}
I20260812 06:17:32.126097 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling LogGCOp(f27414c4566440edaadd764d089e0810): free 117302573 bytes of WAL
I20260812 06:17:32.126318 17656 log_reader.cc:385] T f27414c4566440edaadd764d089e0810: removed 12 log segments from log reader
I20260812 06:17:32.126410 17656 log.cc:1079] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/f27414c4566440edaadd764d089e0810/wal-000000003 (ops 11-15)
I20260812 06:17:32.126464 17656 log.cc:1079] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/f27414c4566440edaadd764d089e0810/wal-000000004 (ops 16-20)
I20260812 06:17:32.126519 17656 log.cc:1079] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/f27414c4566440edaadd764d089e0810/wal-000000005 (ops 21-24)
I20260812 06:17:32.126560 17656 log.cc:1079] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/f27414c4566440edaadd764d089e0810/wal-000000006 (ops 25-29)
I20260812 06:17:32.126597 17656 log.cc:1079] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/f27414c4566440edaadd764d089e0810/wal-000000007 (ops 30-34)
I20260812 06:17:32.126634 17656 log.cc:1079] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/f27414c4566440edaadd764d089e0810/wal-000000008 (ops 35-39)
I20260812 06:17:32.126672 17656 log.cc:1079] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/f27414c4566440edaadd764d089e0810/wal-000000009 (ops 40-44)
I20260812 06:17:32.126711 17656 log.cc:1079] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/f27414c4566440edaadd764d089e0810/wal-000000010 (ops 45-49)
I20260812 06:17:32.126752 17656 log.cc:1079] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/f27414c4566440edaadd764d089e0810/wal-000000011 (ops 50-54)
I20260812 06:17:32.126791 17656 log.cc:1079] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/f27414c4566440edaadd764d089e0810/wal-000000012 (ops 55-58)
I20260812 06:17:32.126828 17656 log.cc:1079] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/f27414c4566440edaadd764d089e0810/wal-000000013 (ops 59-63)
I20260812 06:17:32.126864 17656 log.cc:1079] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/f27414c4566440edaadd764d089e0810/wal-000000014 (ops 64-68)
I20260812 06:17:32.151974 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: LogGCOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.026s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:17:32.152405 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810): perf score=3.181125
I20260812 06:17:32.165304 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.013s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4553933,"delete_count":0,"lbm_write_time_us":4786,"lbm_writes_lt_1ms":114,"reinsert_count":0,"update_count":555}
I20260812 06:17:32.165840 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling LogGCOp(f27414c4566440edaadd764d089e0810): free 11564875 bytes of WAL
I20260812 06:17:32.166100 17656 log_reader.cc:385] T f27414c4566440edaadd764d089e0810: removed 1 log segments from log reader
I20260812 06:17:32.166147 17656 log.cc:1079] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/f27414c4566440edaadd764d089e0810/wal-000000015 (ops 69-72)
I20260812 06:17:32.168277 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: LogGCOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:17:32.168576 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810): perf score=2.188937
I20260812 06:17:32.179291 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3651380,"delete_count":0,"lbm_write_time_us":3439,"lbm_writes_lt_1ms":92,"reinsert_count":0,"update_count":445}
I20260812 06:17:32.179934 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling UndoDeltaBlockGCOp(f27414c4566440edaadd764d089e0810): 472 bytes on disk
I20260812 06:17:32.180328 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: UndoDeltaBlockGCOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:17:32.180748 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling MajorDeltaCompactionOp(f27414c4566440edaadd764d089e0810): perf score=1.000000
I20260812 06:17:32.417584 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: MajorDeltaCompactionOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.237s	user 0.172s	sys 0.058s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979745,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":544,"lbm_read_time_us":14470,"lbm_reads_lt_1ms":766,"lbm_write_time_us":35875,"lbm_writes_lt_1ms":743,"mutex_wait_us":70,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":4352,"thread_start_us":82,"threads_started":1,"update_count":3500}
I20260812 06:17:32.418252 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810): perf score=18.063937
I20260812 06:17:32.490913 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.072s	user 0.035s	sys 0.036s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":27882,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:32.491652 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810): perf score=2.188937
I20260812 06:17:32.508792 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.017s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6577,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:32.509406 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling MajorDeltaCompactionOp(f27414c4566440edaadd764d089e0810): perf score=1.000000
I20260812 06:17:32.723590 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: MajorDeltaCompactionOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.214s	user 0.152s	sys 0.061s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877101,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":667,"lbm_read_time_us":14897,"lbm_reads_lt_1ms":672,"lbm_write_time_us":35046,"lbm_writes_lt_1ms":643,"mutex_wait_us":292,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":22656,"update_count":3000}
I20260812 06:17:32.724236 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810): perf score=14.095187
I20260812 06:17:32.786782 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.062s	user 0.031s	sys 0.020s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":22924,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:32.787263 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810): perf score=2.188937
I20260812 06:17:32.797513 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3980,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:32.797914 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling MajorDeltaCompactionOp(f27414c4566440edaadd764d089e0810): perf score=1.000000
I20260812 06:17:32.969657 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: MajorDeltaCompactionOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.172s	user 0.123s	sys 0.048s 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":813,"lbm_read_time_us":12168,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27220,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:32.970171 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810): perf score=14.095187
I20260812 06:17:33.034710 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.064s	user 0.025s	sys 0.033s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22365,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:33.035274 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810): perf score=2.188937
I20260812 06:17:33.045661 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4093,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:33.046092 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling MajorDeltaCompactionOp(f27414c4566440edaadd764d089e0810): perf score=1.000000
I20260812 06:17:33.238579 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: MajorDeltaCompactionOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.192s	user 0.115s	sys 0.063s 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":653,"lbm_read_time_us":12313,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31181,"lbm_writes_lt_1ms":543,"mutex_wait_us":282,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5120,"update_count":2500}
I20260812 06:17:33.239130 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810): perf score=14.095187
I20260812 06:17:33.299255 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.060s	user 0.014s	sys 0.043s Metrics: {"bytes_written":16409906,"delete_count":0,"lbm_write_time_us":21849,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:33.299757 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810): perf score=2.188937
I20260812 06:17:33.310469 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4283,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:33.310967 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling MajorDeltaCompactionOp(f27414c4566440edaadd764d089e0810): perf score=1.000000
I20260812 06:17:33.495572 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: MajorDeltaCompactionOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.184s	user 0.111s	sys 0.071s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774693,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":847,"lbm_read_time_us":13020,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29738,"lbm_writes_lt_1ms":543,"mutex_wait_us":320,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7808,"update_count":2500}
I20260812 06:17:33.496130 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810): perf score=11.118625
I20260812 06:17:33.537328 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.041s	user 0.013s	sys 0.024s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":17440,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:33.538053 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810): perf score=2.188937
I20260812 06:17:33.559746 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.021s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3815484,"delete_count":0,"lbm_write_time_us":4953,"lbm_writes_lt_1ms":96,"reinsert_count":0,"update_count":465}
I20260812 06:17:33.560187 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810): perf score=2.188937
I20260812 06:17:33.578977 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.019s	user 0.015s	sys 0.002s Metrics: {"bytes_written":3979584,"delete_count":0,"lbm_write_time_us":3682,"lbm_writes_lt_1ms":100,"reinsert_count":0,"update_count":485}
I20260812 06:17:33.579505 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling FlushMRSOp(f27414c4566440edaadd764d089e0810): perf score=1.000000
I20260812 06:17:33.619150 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: FlushMRSOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.039s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":62,"dirs.run_cpu_time_us":219,"dirs.run_wall_time_us":1361,"drs_written":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1922,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:33.619771 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling LogGCOp(f27414c4566440edaadd764d089e0810): free 108535401 bytes of WAL
I20260812 06:17:33.620024 17656 log_reader.cc:385] T f27414c4566440edaadd764d089e0810: removed 11 log segments from log reader
I20260812 06:17:33.620093 17656 log.cc:1079] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/f27414c4566440edaadd764d089e0810/wal-000000016 (ops 73-77)
I20260812 06:17:33.620134 17656 log.cc:1079] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/f27414c4566440edaadd764d089e0810/wal-000000017 (ops 78-82)
I20260812 06:17:33.620172 17656 log.cc:1079] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/f27414c4566440edaadd764d089e0810/wal-000000018 (ops 83-87)
I20260812 06:17:33.620206 17656 log.cc:1079] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/f27414c4566440edaadd764d089e0810/wal-000000019 (ops 88-92)
I20260812 06:17:33.620237 17656 log.cc:1079] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/f27414c4566440edaadd764d089e0810/wal-000000020 (ops 93-96)
I20260812 06:17:33.620260 17656 log.cc:1079] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/f27414c4566440edaadd764d089e0810/wal-000000021 (ops 97-101)
I20260812 06:17:33.620285 17656 log.cc:1079] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/f27414c4566440edaadd764d089e0810/wal-000000022 (ops 102-106)
I20260812 06:17:33.620318 17656 log.cc:1079] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/f27414c4566440edaadd764d089e0810/wal-000000023 (ops 107-111)
I20260812 06:17:33.620350 17656 log.cc:1079] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/f27414c4566440edaadd764d089e0810/wal-000000024 (ops 112-116)
I20260812 06:17:33.620379 17656 log.cc:1079] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/f27414c4566440edaadd764d089e0810/wal-000000025 (ops 117-120)
I20260812 06:17:33.620414 17656 log.cc:1079] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/f27414c4566440edaadd764d089e0810/wal-000000026 (ops 121-125)
I20260812 06:17:33.647702 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: LogGCOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.028s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:17:33.648483 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling UndoDeltaBlockGCOp(f27414c4566440edaadd764d089e0810): 447 bytes on disk
I20260812 06:17:33.649209 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: UndoDeltaBlockGCOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":83,"lbm_reads_lt_1ms":4}
I20260812 06:17:33.650084 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810): perf score=2.188937
I20260812 06:17:33.679143 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.029s	user 0.000s	sys 0.013s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5775,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:33.679625 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810): perf score=2.188937
I20260812 06:17:33.694221 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.014s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5705,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:33.694729 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling MajorDeltaCompactionOp(f27414c4566440edaadd764d089e0810): perf score=1.000000
I20260812 06:17:33.935474 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: MajorDeltaCompactionOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.241s	user 0.149s	sys 0.083s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979866,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":665,"lbm_read_time_us":15877,"lbm_reads_lt_1ms":775,"lbm_write_time_us":39061,"lbm_writes_lt_1ms":743,"mutex_wait_us":28,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":6656,"thread_start_us":97,"threads_started":1,"update_count":3500}
I20260812 06:17:33.936281 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810): perf score=18.063937
I20260812 06:17:34.007264 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.071s	user 0.026s	sys 0.036s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":27125,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:34.007726 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810): perf score=2.188937
I20260812 06:17:34.018430 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3793,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:34.018973 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling MajorDeltaCompactionOp(f27414c4566440edaadd764d089e0810): perf score=1.000000
I20260812 06:17:34.220636 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: MajorDeltaCompactionOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.201s	user 0.125s	sys 0.076s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":540,"lbm_read_time_us":13919,"lbm_reads_lt_1ms":672,"lbm_write_time_us":33428,"lbm_writes_lt_1ms":643,"mutex_wait_us":314,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":24448,"update_count":3000}
I20260812 06:17:34.221413 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810): perf score=14.095187
I20260812 06:17:34.269958 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.048s	user 0.028s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21066,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:34.270452 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810): perf score=2.188937
I20260812 06:17:34.286487 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.016s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6007,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:34.287040 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling MajorDeltaCompactionOp(f27414c4566440edaadd764d089e0810): perf score=1.000000
I20260812 06:17:34.462035 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: MajorDeltaCompactionOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.175s	user 0.118s	sys 0.051s 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":575,"lbm_read_time_us":13761,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28576,"lbm_writes_lt_1ms":543,"mutex_wait_us":311,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":41472,"update_count":2500}
I20260812 06:17:34.462755 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810): perf score=14.095187
I20260812 06:17:34.525646 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.063s	user 0.037s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22534,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:34.526413 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810): perf score=2.188937
I20260812 06:17:34.538681 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.012s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4676,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:34.539250 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling MajorDeltaCompactionOp(f27414c4566440edaadd764d089e0810): perf score=1.000000
I20260812 06:17:34.711351 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: MajorDeltaCompactionOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.172s	user 0.125s	sys 0.046s 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":782,"lbm_read_time_us":10615,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30833,"lbm_writes_lt_1ms":543,"mutex_wait_us":30,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12800,"update_count":2500}
I20260812 06:17:34.712015 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810): perf score=14.095187
I20260812 06:17:34.768908 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.057s	user 0.025s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20850,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:34.769624 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810): perf score=2.188937
I20260812 06:17:34.781615 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.012s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4608,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:34.782145 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling MajorDeltaCompactionOp(f27414c4566440edaadd764d089e0810): perf score=1.000000
I20260812 06:17:34.973642 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: MajorDeltaCompactionOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.191s	user 0.111s	sys 0.077s 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":667,"lbm_read_time_us":14132,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29700,"lbm_writes_lt_1ms":543,"mutex_wait_us":41,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:17:34.974134 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810): perf score=14.095187
I20260812 06:17:35.024339 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.050s	user 0.025s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19777,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:35.024896 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810): perf score=2.188937
I20260812 06:17:35.045768 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.021s	user 0.010s	sys 0.011s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4146,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.046535 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling FlushMRSOp(f27414c4566440edaadd764d089e0810): perf score=1.000000
I20260812 06:17:35.081713 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: FlushMRSOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.035s	user 0.034s	sys 0.000s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":63,"dirs.run_cpu_time_us":156,"dirs.run_wall_time_us":1140,"drs_written":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2083,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:35.082922 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling LogGCOp(f27414c4566440edaadd764d089e0810): free 120553631 bytes of WAL
I20260812 06:17:35.083204 17656 log_reader.cc:385] T f27414c4566440edaadd764d089e0810: removed 12 log segments from log reader
I20260812 06:17:35.083271 17656 log.cc:1079] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/f27414c4566440edaadd764d089e0810/wal-000000027 (ops 126-130)
I20260812 06:17:35.083375 17656 log.cc:1079] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/f27414c4566440edaadd764d089e0810/wal-000000028 (ops 131-135)
I20260812 06:17:35.083427 17656 log.cc:1079] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/f27414c4566440edaadd764d089e0810/wal-000000029 (ops 136-140)
I20260812 06:17:35.083464 17656 log.cc:1079] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/f27414c4566440edaadd764d089e0810/wal-000000030 (ops 141-144)
I20260812 06:17:35.083508 17656 log.cc:1079] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/f27414c4566440edaadd764d089e0810/wal-000000031 (ops 145-149)
I20260812 06:17:35.083606 17656 log.cc:1079] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/f27414c4566440edaadd764d089e0810/wal-000000032 (ops 150-154)
I20260812 06:17:35.083657 17656 log.cc:1079] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/f27414c4566440edaadd764d089e0810/wal-000000033 (ops 155-159)
I20260812 06:17:35.083732 17656 log.cc:1079] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/f27414c4566440edaadd764d089e0810/wal-000000034 (ops 160-164)
I20260812 06:17:35.083778 17656 log.cc:1079] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/f27414c4566440edaadd764d089e0810/wal-000000035 (ops 165-169)
I20260812 06:17:35.083865 17656 log.cc:1079] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/f27414c4566440edaadd764d089e0810/wal-000000036 (ops 170-174)
I20260812 06:17:35.083913 17656 log.cc:1079] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/f27414c4566440edaadd764d089e0810/wal-000000037 (ops 175-178)
I20260812 06:17:35.083992 17656 log.cc:1079] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1: Deleting log segment in path: /tmp/dist-test-taskjtvBCw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445158667-17139-0/minicluster-data/ts-0-root/wals/f27414c4566440edaadd764d089e0810/wal-000000038 (ops 179-183)
I20260812 06:17:35.110430 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: LogGCOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.027s	user 0.003s	sys 0.023s Metrics: {}
I20260812 06:17:35.110812 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810): perf score=3.181125
I20260812 06:17:35.134545 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.024s	user 0.016s	sys 0.000s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":6559,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:35.135066 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810): perf score=2.188937
I20260812 06:17:35.144593 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3694,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:35.145046 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling MajorDeltaCompactionOp(f27414c4566440edaadd764d089e0810): perf score=1.000000
I20260812 06:17:35.377744 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: MajorDeltaCompactionOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.233s	user 0.147s	sys 0.075s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979739,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":511,"lbm_read_time_us":13614,"lbm_reads_lt_1ms":774,"lbm_write_time_us":36471,"lbm_writes_lt_1ms":743,"mutex_wait_us":44,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":78,"threads_started":1,"update_count":3500}
I20260812 06:17:35.378549 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810): perf score=18.063937
I20260812 06:17:35.445559 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.066s	user 0.034s	sys 0.019s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":24117,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:35.446079 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling UndoDeltaBlockGCOp(f27414c4566440edaadd764d089e0810): 448 bytes on disk
I20260812 06:17:35.446568 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: UndoDeltaBlockGCOp(f27414c4566440edaadd764d089e0810) 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:17:35.447120 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810): perf score=2.188937
I20260812 06:17:35.458482 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: FlushDeltaMemStoresOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.011s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4282,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.458992 17767 maintenance_manager.cc:419] P 190d05ce5600454f85031494090af0c1: Scheduling MajorDeltaCompactionOp(f27414c4566440edaadd764d089e0810): perf score=1.000000
I20260812 06:17:35.544268 17139 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.962s	user 1.846s	sys 0.191s
I20260812 06:17:35.613021 17139 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.068s	user 0.001s	sys 0.000s
I20260812 06:17:35.613575 17139 tablet_server.cc:179] TabletServer@127.16.188.193:0 shutting down...
I20260812 06:17:35.636176 17656 maintenance_manager.cc:643] P 190d05ce5600454f85031494090af0c1: MajorDeltaCompactionOp(f27414c4566440edaadd764d089e0810) complete. Timing: real 0.177s	user 0.124s	sys 0.051s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877103,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":499,"lbm_read_time_us":14403,"lbm_reads_lt_1ms":668,"lbm_write_time_us":28579,"lbm_writes_lt_1ms":643,"mutex_wait_us":1,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":10240,"update_count":3000}
I20260812 06:17:35.637478 17139 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:35.637681 17139 tablet_replica.cc:333] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1: stopping tablet replica
I20260812 06:17:35.637841 17139 raft_consensus.cc:2243] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:35.638022 17139 raft_consensus.cc:2272] T f27414c4566440edaadd764d089e0810 P 190d05ce5600454f85031494090af0c1 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:35.653600 17139 tablet_server.cc:196] TabletServer@127.16.188.193:0 shutdown complete.
I20260812 06:17:35.693925 17139 master.cc:562] Master@127.16.188.254:39677 shutting down...
I20260812 06:17:35.697230 17139 raft_consensus.cc:2243] T 00000000000000000000000000000000 P c5da48cc5eac45649f5882293d5f4e46 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:35.697469 17139 raft_consensus.cc:2272] T 00000000000000000000000000000000 P c5da48cc5eac45649f5882293d5f4e46 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:35.697571 17139 tablet_replica.cc:333] T 00000000000000000000000000000000 P c5da48cc5eac45649f5882293d5f4e46: stopping tablet replica
I20260812 06:17:35.709961 17139 master.cc:584] Master@127.16.188.254:39677 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5391 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10629 ms total)

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