[==========] 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:20:29.393993 24927 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.24.87.254:43257
I20260812 06:20:29.395010 24927 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:20:29.395605 24927 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:29.402247 24942 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:29.402315 24938 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:29.402398 24927 server_base.cc:1061] running on GCE node
W20260812 06:20:29.402558 24934 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:29.403043 24927 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:29.403167 24927 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:29.403229 24927 hybrid_clock.cc:648] HybridClock initialized: now 1786515629403214 us; error 0 us; skew 500 ppm
I20260812 06:20:29.404996 24927 webserver.cc:533] Webserver started at http://127.24.87.254:46079/ using document root <none> and password file <none>
I20260812 06:20:29.405553 24927 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:29.405642 24927 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:29.405884 24927 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:29.407518 24927 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515629383304-24927-0/minicluster-data/master-0-root/instance:
uuid: "ea6db02d47db4c8d8ed3db0424d7b3f2"
format_stamp: "Formatted at 2026-08-12 06:20:29 on dist-test-slave-3h5h"
I20260812 06:20:29.411254 24927 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.002s	sys 0.003s
I20260812 06:20:29.413417 24949 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:29.414532 24927 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:20:29.414678 24927 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515629383304-24927-0/minicluster-data/master-0-root
uuid: "ea6db02d47db4c8d8ed3db0424d7b3f2"
format_stamp: "Formatted at 2026-08-12 06:20:29 on dist-test-slave-3h5h"
I20260812 06:20:29.414793 24927 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515629383304-24927-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515629383304-24927-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515629383304-24927-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:29.433745 24927 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:29.434417 24927 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:20:29.434605 24927 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:29.442888 25034 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.24.87.254:43257 every 8 connection(s)
I20260812 06:20:29.442911 24927 rpc_server.cc:307] RPC server started. Bound to: 127.24.87.254:43257
I20260812 06:20:29.445284 25037 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:29.453615 25037 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P ea6db02d47db4c8d8ed3db0424d7b3f2: Bootstrap starting.
I20260812 06:20:29.457034 25037 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P ea6db02d47db4c8d8ed3db0424d7b3f2: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:29.458084 25037 log.cc:826] T 00000000000000000000000000000000 P ea6db02d47db4c8d8ed3db0424d7b3f2: Log is configured to *not* fsync() on all Append() calls
I20260812 06:20:29.461206 25037 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P ea6db02d47db4c8d8ed3db0424d7b3f2: No bootstrap required, opened a new log
I20260812 06:20:29.465071 25037 raft_consensus.cc:359] T 00000000000000000000000000000000 P ea6db02d47db4c8d8ed3db0424d7b3f2 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ea6db02d47db4c8d8ed3db0424d7b3f2" member_type: VOTER }
I20260812 06:20:29.465274 25037 raft_consensus.cc:385] T 00000000000000000000000000000000 P ea6db02d47db4c8d8ed3db0424d7b3f2 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:29.465379 25037 raft_consensus.cc:740] T 00000000000000000000000000000000 P ea6db02d47db4c8d8ed3db0424d7b3f2 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: ea6db02d47db4c8d8ed3db0424d7b3f2, State: Initialized, Role: FOLLOWER
I20260812 06:20:29.466104 25037 consensus_queue.cc:260] T 00000000000000000000000000000000 P ea6db02d47db4c8d8ed3db0424d7b3f2 [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: "ea6db02d47db4c8d8ed3db0424d7b3f2" member_type: VOTER }
I20260812 06:20:29.466288 25037 raft_consensus.cc:399] T 00000000000000000000000000000000 P ea6db02d47db4c8d8ed3db0424d7b3f2 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:29.466382 25037 raft_consensus.cc:493] T 00000000000000000000000000000000 P ea6db02d47db4c8d8ed3db0424d7b3f2 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:29.466512 25037 raft_consensus.cc:3060] T 00000000000000000000000000000000 P ea6db02d47db4c8d8ed3db0424d7b3f2 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:29.467737 25037 raft_consensus.cc:515] T 00000000000000000000000000000000 P ea6db02d47db4c8d8ed3db0424d7b3f2 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ea6db02d47db4c8d8ed3db0424d7b3f2" member_type: VOTER }
I20260812 06:20:29.468284 25037 leader_election.cc:304] T 00000000000000000000000000000000 P ea6db02d47db4c8d8ed3db0424d7b3f2 [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: ea6db02d47db4c8d8ed3db0424d7b3f2; no voters: 
I20260812 06:20:29.468722 25037 leader_election.cc:290] T 00000000000000000000000000000000 P ea6db02d47db4c8d8ed3db0424d7b3f2 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:29.468892 25042 raft_consensus.cc:2804] T 00000000000000000000000000000000 P ea6db02d47db4c8d8ed3db0424d7b3f2 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:29.469187 25042 raft_consensus.cc:697] T 00000000000000000000000000000000 P ea6db02d47db4c8d8ed3db0424d7b3f2 [term 1 LEADER]: Becoming Leader. State: Replica: ea6db02d47db4c8d8ed3db0424d7b3f2, State: Running, Role: LEADER
I20260812 06:20:29.469659 25042 consensus_queue.cc:237] T 00000000000000000000000000000000 P ea6db02d47db4c8d8ed3db0424d7b3f2 [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: "ea6db02d47db4c8d8ed3db0424d7b3f2" member_type: VOTER }
I20260812 06:20:29.469889 25037 sys_catalog.cc:565] T 00000000000000000000000000000000 P ea6db02d47db4c8d8ed3db0424d7b3f2 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:29.474455 25046 sys_catalog.cc:455] T 00000000000000000000000000000000 P ea6db02d47db4c8d8ed3db0424d7b3f2 [sys.catalog]: SysCatalogTable state changed. Reason: New leader ea6db02d47db4c8d8ed3db0424d7b3f2. Latest consensus state: current_term: 1 leader_uuid: "ea6db02d47db4c8d8ed3db0424d7b3f2" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ea6db02d47db4c8d8ed3db0424d7b3f2" member_type: VOTER } }
I20260812 06:20:29.474594 25046 sys_catalog.cc:458] T 00000000000000000000000000000000 P ea6db02d47db4c8d8ed3db0424d7b3f2 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:29.474882 25045 sys_catalog.cc:455] T 00000000000000000000000000000000 P ea6db02d47db4c8d8ed3db0424d7b3f2 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "ea6db02d47db4c8d8ed3db0424d7b3f2" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ea6db02d47db4c8d8ed3db0424d7b3f2" member_type: VOTER } }
I20260812 06:20:29.474974 25045 sys_catalog.cc:458] T 00000000000000000000000000000000 P ea6db02d47db4c8d8ed3db0424d7b3f2 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:29.475208 25058 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:29.475502 24927 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:29.478173 25058 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:29.484025 25058 catalog_manager.cc:1383] Generated new cluster ID: 6b74e8cce4014d94bbca5ffeac407456
I20260812 06:20:29.484167 25058 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:29.513459 25058 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:29.514390 25058 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:29.523815 25058 catalog_manager.cc:6092] T 00000000000000000000000000000000 P ea6db02d47db4c8d8ed3db0424d7b3f2: Generated new TSK 0
I20260812 06:20:29.524531 25058 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:29.540287 24927 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:29.543450 25075 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:29.543496 25072 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:29.543742 24927 server_base.cc:1061] running on GCE node
W20260812 06:20:29.543545 25071 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:29.544076 24927 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:29.544134 24927 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:29.544157 24927 hybrid_clock.cc:648] HybridClock initialized: now 1786515629544157 us; error 0 us; skew 500 ppm
I20260812 06:20:29.545140 24927 webserver.cc:533] Webserver started at http://127.24.87.193:37915/ using document root <none> and password file <none>
I20260812 06:20:29.545313 24927 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:29.545373 24927 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:29.545451 24927 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:29.545885 24927 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515629383304-24927-0/minicluster-data/ts-0-root/instance:
uuid: "4ffafb558e224cebba5aca5acfb114e0"
format_stamp: "Formatted at 2026-08-12 06:20:29 on dist-test-slave-3h5h"
I20260812 06:20:29.547796 24927 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:29.548956 25083 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:29.549243 24927 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:29.549316 24927 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515629383304-24927-0/minicluster-data/ts-0-root
uuid: "4ffafb558e224cebba5aca5acfb114e0"
format_stamp: "Formatted at 2026-08-12 06:20:29 on dist-test-slave-3h5h"
I20260812 06:20:29.549403 24927 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515629383304-24927-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515629383304-24927-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515629383304-24927-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:29.562826 24927 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:29.563272 24927 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:29.563794 24927 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:29.564631 24927 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:29.564692 24927 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:29.564780 24927 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:29.564822 24927 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:29.571341 24927 rpc_server.cc:307] RPC server started. Bound to: 127.24.87.193:35467
I20260812 06:20:29.571370 25197 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.24.87.193:35467 every 8 connection(s)
I20260812 06:20:29.584923 25198 heartbeater.cc:344] Connected to a master server at 127.24.87.254:43257
I20260812 06:20:29.585202 25198 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:29.585690 25198 heartbeater.cc:507] Master 127.24.87.254:43257 requested a full tablet report, sending...
I20260812 06:20:29.587097 24972 ts_manager.cc:194] Registered new tserver with Master: 4ffafb558e224cebba5aca5acfb114e0 (127.24.87.193:35467)
I20260812 06:20:29.587574 24927 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.015550707s
I20260812 06:20:29.588629 24972 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:52150
I20260812 06:20:29.597025 24972 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:52166:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:20:29.610627 25130 tablet_service.cc:1511] Processing CreateTablet for tablet 290dbf5fcbe243ffa027795750ed71f6 (DEFAULT_TABLE table=heavy-update-compaction-test [id=01d9187eb6f44167813be1662b43d308]), partition=
I20260812 06:20:29.611088 25130 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 290dbf5fcbe243ffa027795750ed71f6. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:29.613484 25216 tablet_bootstrap.cc:492] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0: Bootstrap starting.
I20260812 06:20:29.614404 25216 tablet_bootstrap.cc:654] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:29.615684 25216 tablet_bootstrap.cc:492] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0: No bootstrap required, opened a new log
I20260812 06:20:29.615804 25216 ts_tablet_manager.cc:1403] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:29.616237 25216 raft_consensus.cc:359] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4ffafb558e224cebba5aca5acfb114e0" member_type: VOTER last_known_addr { host: "127.24.87.193" port: 35467 } }
I20260812 06:20:29.616357 25216 raft_consensus.cc:385] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:29.616405 25216 raft_consensus.cc:740] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 4ffafb558e224cebba5aca5acfb114e0, State: Initialized, Role: FOLLOWER
I20260812 06:20:29.616544 25216 consensus_queue.cc:260] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0 [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: "4ffafb558e224cebba5aca5acfb114e0" member_type: VOTER last_known_addr { host: "127.24.87.193" port: 35467 } }
I20260812 06:20:29.616649 25216 raft_consensus.cc:399] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:29.616698 25216 raft_consensus.cc:493] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:29.616752 25216 raft_consensus.cc:3060] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:29.617836 25216 raft_consensus.cc:515] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4ffafb558e224cebba5aca5acfb114e0" member_type: VOTER last_known_addr { host: "127.24.87.193" port: 35467 } }
I20260812 06:20:29.617995 25216 leader_election.cc:304] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0 [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: 4ffafb558e224cebba5aca5acfb114e0; no voters: 
I20260812 06:20:29.618217 25216 leader_election.cc:290] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:29.618351 25219 raft_consensus.cc:2804] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:29.618688 25219 raft_consensus.cc:697] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0 [term 1 LEADER]: Becoming Leader. State: Replica: 4ffafb558e224cebba5aca5acfb114e0, State: Running, Role: LEADER
I20260812 06:20:29.618830 25216 ts_tablet_manager.cc:1434] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:20:29.618885 25219 consensus_queue.cc:237] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0 [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: "4ffafb558e224cebba5aca5acfb114e0" member_type: VOTER last_known_addr { host: "127.24.87.193" port: 35467 } }
I20260812 06:20:29.619385 25198 heartbeater.cc:499] Master 127.24.87.254:43257 was elected leader, sending a full tablet report...
I20260812 06:20:29.621788 24972 catalog_manager.cc:5719] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0 reported cstate change: term changed from 0 to 1, leader changed from <none> to 4ffafb558e224cebba5aca5acfb114e0 (127.24.87.193). New cstate: current_term: 1 leader_uuid: "4ffafb558e224cebba5aca5acfb114e0" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4ffafb558e224cebba5aca5acfb114e0" member_type: VOTER last_known_addr { host: "127.24.87.193" port: 35467 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:29.689970 24927 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.058s	user 0.024s	sys 0.004s
I20260812 06:20:29.822396 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling FlushMRSOp(290dbf5fcbe243ffa027795750ed71f6): perf score=19.054940
I20260812 06:20:30.000406 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: FlushMRSOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.178s	user 0.127s	sys 0.044s Metrics: {"bytes_written":12307490,"cfile_init":1,"compiler_manager_pool.queue_time_us":190,"delete_count":0,"dirs.queue_time_us":66,"dirs.run_cpu_time_us":233,"dirs.run_wall_time_us":1116,"drs_written":1,"lbm_read_time_us":75,"lbm_reads_lt_1ms":4,"lbm_write_time_us":45075,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":126,"threads_started":1,"update_count":1500}
I20260812 06:20:30.001689 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling LogGCOp(290dbf5fcbe243ffa027795750ed71f6): free 20743880 bytes of WAL
I20260812 06:20:30.002004 25091 log_reader.cc:385] T 290dbf5fcbe243ffa027795750ed71f6: removed 2 log segments from log reader
I20260812 06:20:30.002074 25091 log.cc:1079] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/290dbf5fcbe243ffa027795750ed71f6/wal-000000001 (ops 1-6)
I20260812 06:20:30.002195 25091 log.cc:1079] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/290dbf5fcbe243ffa027795750ed71f6/wal-000000002 (ops 7-11)
I20260812 06:20:30.007580 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: LogGCOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.006s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:20:30.008050 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling UndoDeltaBlockGCOp(290dbf5fcbe243ffa027795750ed71f6): 16411393 bytes on disk
I20260812 06:20:30.008723 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: UndoDeltaBlockGCOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":80,"lbm_reads_lt_1ms":4}
I20260812 06:20:30.009207 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6): perf score=2.188937
I20260812 06:20:30.024832 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.015s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5497,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:30.025552 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling MajorDeltaCompactionOp(290dbf5fcbe243ffa027795750ed71f6): perf score=1.000000
I20260812 06:20:30.177489 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: MajorDeltaCompactionOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.152s	user 0.109s	sys 0.039s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1370,"lbm_read_time_us":8730,"lbm_reads_lt_1ms":460,"lbm_write_time_us":24480,"lbm_writes_lt_1ms":443,"mutex_wait_us":536,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4736,"thread_start_us":385,"threads_started":5,"update_count":2000}
I20260812 06:20:30.178141 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6): perf score=10.126437
I20260812 06:20:30.224023 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.046s	user 0.027s	sys 0.015s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":20473,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:30.224538 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6): perf score=2.188937
I20260812 06:20:30.236644 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4321,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:30.237138 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling MajorDeltaCompactionOp(290dbf5fcbe243ffa027795750ed71f6): perf score=1.000000
I20260812 06:20:30.369889 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: MajorDeltaCompactionOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.133s	user 0.113s	sys 0.020s 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":177,"lbm_read_time_us":9604,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25894,"lbm_writes_lt_1ms":443,"mutex_wait_us":25,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10880,"update_count":2000}
I20260812 06:20:30.370498 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6): perf score=10.126437
I20260812 06:20:30.402915 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.032s	user 0.021s	sys 0.009s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":13978,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:30.403398 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6): perf score=2.188937
I20260812 06:20:30.421005 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.017s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6005,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:30.422176 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling MajorDeltaCompactionOp(290dbf5fcbe243ffa027795750ed71f6): perf score=1.000000
I20260812 06:20:30.549273 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: MajorDeltaCompactionOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.127s	user 0.111s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":58,"lbm_read_time_us":8916,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26382,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":24448,"update_count":2000}
I20260812 06:20:30.549907 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6): perf score=10.126437
I20260812 06:20:30.595513 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.045s	user 0.017s	sys 0.024s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14551,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:30.596101 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6): perf score=2.188937
I20260812 06:20:30.612159 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.016s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5984,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:30.612704 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling MajorDeltaCompactionOp(290dbf5fcbe243ffa027795750ed71f6): perf score=1.000000
I20260812 06:20:30.771503 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: MajorDeltaCompactionOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.159s	user 0.096s	sys 0.061s 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":375,"lbm_read_time_us":11755,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24320,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:20:30.771970 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6): perf score=10.126437
I20260812 06:20:30.823065 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.051s	user 0.034s	sys 0.004s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17770,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:30.823586 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6): perf score=2.188937
I20260812 06:20:30.834991 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.011s	user 0.008s	sys 0.001s 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:20:30.835541 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling MajorDeltaCompactionOp(290dbf5fcbe243ffa027795750ed71f6): perf score=1.000000
I20260812 06:20:30.962818 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: MajorDeltaCompactionOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.127s	user 0.095s	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":292,"lbm_read_time_us":8381,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26838,"lbm_writes_lt_1ms":443,"mutex_wait_us":95,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:20:30.965758 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6): perf score=10.126437
I20260812 06:20:31.013955 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.048s	user 0.039s	sys 0.004s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":19397,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:31.014464 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6): perf score=2.188937
I20260812 06:20:31.025249 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4072,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:31.025954 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling MajorDeltaCompactionOp(290dbf5fcbe243ffa027795750ed71f6): perf score=1.000000
I20260812 06:20:31.151839 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: MajorDeltaCompactionOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.126s	user 0.110s	sys 0.013s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672280,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":248,"lbm_read_time_us":8871,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23921,"lbm_writes_lt_1ms":443,"mutex_wait_us":65,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":2000}
I20260812 06:20:31.152489 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6): perf score=10.126437
I20260812 06:20:31.197777 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.045s	user 0.018s	sys 0.026s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":18019,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:31.198254 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling FlushMRSOp(290dbf5fcbe243ffa027795750ed71f6): perf score=1.000000
I20260812 06:20:31.236726 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: FlushMRSOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.038s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":63,"dirs.run_cpu_time_us":276,"dirs.run_wall_time_us":1666,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1902,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:31.237759 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6): perf score=3.181125
I20260812 06:20:31.262090 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.024s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4389828,"delete_count":0,"lbm_write_time_us":4569,"lbm_writes_lt_1ms":110,"reinsert_count":0,"update_count":535}
I20260812 06:20:31.262611 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling LogGCOp(290dbf5fcbe243ffa027795750ed71f6): free 112239259 bytes of WAL
I20260812 06:20:31.262890 25091 log_reader.cc:385] T 290dbf5fcbe243ffa027795750ed71f6: removed 11 log segments from log reader
I20260812 06:20:31.262936 25091 log.cc:1079] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/290dbf5fcbe243ffa027795750ed71f6/wal-000000003 (ops 12-16)
I20260812 06:20:31.262971 25091 log.cc:1079] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/290dbf5fcbe243ffa027795750ed71f6/wal-000000004 (ops 17-20)
I20260812 06:20:31.263043 25091 log.cc:1079] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/290dbf5fcbe243ffa027795750ed71f6/wal-000000005 (ops 21-25)
I20260812 06:20:31.263118 25091 log.cc:1079] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/290dbf5fcbe243ffa027795750ed71f6/wal-000000006 (ops 26-30)
I20260812 06:20:31.263187 25091 log.cc:1079] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/290dbf5fcbe243ffa027795750ed71f6/wal-000000007 (ops 31-35)
I20260812 06:20:31.263219 25091 log.cc:1079] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/290dbf5fcbe243ffa027795750ed71f6/wal-000000008 (ops 36-40)
I20260812 06:20:31.263281 25091 log.cc:1079] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/290dbf5fcbe243ffa027795750ed71f6/wal-000000009 (ops 41-45)
I20260812 06:20:31.263327 25091 log.cc:1079] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/290dbf5fcbe243ffa027795750ed71f6/wal-000000010 (ops 46-50)
I20260812 06:20:31.263379 25091 log.cc:1079] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/290dbf5fcbe243ffa027795750ed71f6/wal-000000011 (ops 51-55)
I20260812 06:20:31.263422 25091 log.cc:1079] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/290dbf5fcbe243ffa027795750ed71f6/wal-000000012 (ops 56-60)
I20260812 06:20:31.263475 25091 log.cc:1079] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/290dbf5fcbe243ffa027795750ed71f6/wal-000000013 (ops 61-65)
I20260812 06:20:31.290673 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: LogGCOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.028s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:20:31.291118 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6): perf score=2.188937
I20260812 06:20:31.313874 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.023s	user 0.009s	sys 0.006s Metrics: {"bytes_written":3815484,"delete_count":0,"lbm_write_time_us":6057,"lbm_writes_lt_1ms":96,"reinsert_count":0,"update_count":465}
I20260812 06:20:31.314345 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6): perf score=2.188937
I20260812 06:20:31.326288 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.012s	user 0.000s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4462,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:31.327013 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling UndoDeltaBlockGCOp(290dbf5fcbe243ffa027795750ed71f6): 447 bytes on disk
I20260812 06:20:31.327575 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: UndoDeltaBlockGCOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":88,"lbm_reads_lt_1ms":4}
I20260812 06:20:31.328063 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling MajorDeltaCompactionOp(290dbf5fcbe243ffa027795750ed71f6): perf score=1.000000
I20260812 06:20:31.534652 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: MajorDeltaCompactionOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.206s	user 0.169s	sys 0.036s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877332,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1263,"lbm_read_time_us":11718,"lbm_reads_lt_1ms":674,"lbm_write_time_us":38721,"lbm_writes_lt_1ms":643,"mutex_wait_us":384,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3456,"thread_start_us":132,"threads_started":1,"update_count":3000}
I20260812 06:20:31.535555 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6): perf score=14.095187
I20260812 06:20:31.593881 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.058s	user 0.037s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22690,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:31.594429 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6): perf score=2.188937
I20260812 06:20:31.607496 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4881,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:31.607981 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling MajorDeltaCompactionOp(290dbf5fcbe243ffa027795750ed71f6): perf score=1.000000
I20260812 06:20:31.795228 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: MajorDeltaCompactionOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.187s	user 0.130s	sys 0.057s 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":220,"lbm_read_time_us":11942,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34639,"lbm_writes_lt_1ms":543,"mutex_wait_us":48,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16896,"update_count":2500}
I20260812 06:20:31.798774 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6): perf score=14.095187
I20260812 06:20:31.854089 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.055s	user 0.032s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20903,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:31.854666 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6): perf score=2.188937
I20260812 06:20:31.865654 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4455,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:31.866123 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling MajorDeltaCompactionOp(290dbf5fcbe243ffa027795750ed71f6): perf score=1.000000
I20260812 06:20:32.040460 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: MajorDeltaCompactionOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.174s	user 0.134s	sys 0.036s 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":194,"lbm_read_time_us":13796,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28203,"lbm_writes_lt_1ms":543,"mutex_wait_us":3,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2500}
I20260812 06:20:32.041026 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6): perf score=14.095187
I20260812 06:20:32.106148 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.065s	user 0.026s	sys 0.030s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20923,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:32.106724 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6): perf score=2.188937
I20260812 06:20:32.123409 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.017s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6268,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:32.124091 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling MajorDeltaCompactionOp(290dbf5fcbe243ffa027795750ed71f6): perf score=1.000000
I20260812 06:20:32.318712 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: MajorDeltaCompactionOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.194s	user 0.132s	sys 0.051s 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":143,"lbm_read_time_us":12899,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30739,"lbm_writes_lt_1ms":543,"mutex_wait_us":27,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":70144,"update_count":2500}
I20260812 06:20:32.319360 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6): perf score=14.095187
I20260812 06:20:32.370623 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.051s	user 0.030s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19224,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:32.371381 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6): perf score=2.188937
I20260812 06:20:32.391304 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.020s	user 0.009s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4307,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:32.391894 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling MajorDeltaCompactionOp(290dbf5fcbe243ffa027795750ed71f6): perf score=1.000000
I20260812 06:20:32.574404 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: MajorDeltaCompactionOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.182s	user 0.118s	sys 0.055s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":679,"lbm_read_time_us":13905,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27750,"lbm_writes_lt_1ms":543,"mutex_wait_us":306,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3968,"update_count":2500}
I20260812 06:20:32.575126 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6): perf score=14.095187
I20260812 06:20:32.625919 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.051s	user 0.030s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19630,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:32.626385 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6): perf score=2.188937
I20260812 06:20:32.638602 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4441,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:32.639145 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling MajorDeltaCompactionOp(290dbf5fcbe243ffa027795750ed71f6): perf score=1.000000
I20260812 06:20:32.817313 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: MajorDeltaCompactionOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.177s	user 0.103s	sys 0.059s 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":746,"lbm_read_time_us":9624,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27318,"lbm_writes_lt_1ms":543,"mutex_wait_us":53,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:20:32.817963 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6): perf score=14.095187
I20260812 06:20:32.865268 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.047s	user 0.026s	sys 0.021s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":21691,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:32.865774 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6): perf score=2.188937
I20260812 06:20:32.879809 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.014s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5422,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:32.880391 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling FlushMRSOp(290dbf5fcbe243ffa027795750ed71f6): perf score=1.000000
I20260812 06:20:32.913604 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: FlushMRSOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.033s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":86,"dirs.run_cpu_time_us":406,"dirs.run_wall_time_us":1914,"drs_written":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2216,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:20:32.914487 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling LogGCOp(290dbf5fcbe243ffa027795750ed71f6): free 133024426 bytes of WAL
I20260812 06:20:32.914817 25091 log_reader.cc:385] T 290dbf5fcbe243ffa027795750ed71f6: removed 13 log segments from log reader
I20260812 06:20:32.914882 25091 log.cc:1079] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/290dbf5fcbe243ffa027795750ed71f6/wal-000000014 (ops 66-70)
I20260812 06:20:32.914922 25091 log.cc:1079] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/290dbf5fcbe243ffa027795750ed71f6/wal-000000015 (ops 71-75)
I20260812 06:20:32.914954 25091 log.cc:1079] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/290dbf5fcbe243ffa027795750ed71f6/wal-000000016 (ops 76-80)
I20260812 06:20:32.914985 25091 log.cc:1079] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/290dbf5fcbe243ffa027795750ed71f6/wal-000000017 (ops 81-85)
I20260812 06:20:32.915012 25091 log.cc:1079] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/290dbf5fcbe243ffa027795750ed71f6/wal-000000018 (ops 86-90)
I20260812 06:20:32.915037 25091 log.cc:1079] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/290dbf5fcbe243ffa027795750ed71f6/wal-000000019 (ops 91-94)
I20260812 06:20:32.915059 25091 log.cc:1079] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/290dbf5fcbe243ffa027795750ed71f6/wal-000000020 (ops 95-99)
I20260812 06:20:32.915081 25091 log.cc:1079] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/290dbf5fcbe243ffa027795750ed71f6/wal-000000021 (ops 100-104)
I20260812 06:20:32.915104 25091 log.cc:1079] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/290dbf5fcbe243ffa027795750ed71f6/wal-000000022 (ops 105-109)
I20260812 06:20:32.915140 25091 log.cc:1079] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/290dbf5fcbe243ffa027795750ed71f6/wal-000000023 (ops 110-114)
I20260812 06:20:32.915180 25091 log.cc:1079] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/290dbf5fcbe243ffa027795750ed71f6/wal-000000024 (ops 115-119)
I20260812 06:20:32.915217 25091 log.cc:1079] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/290dbf5fcbe243ffa027795750ed71f6/wal-000000025 (ops 120-124)
I20260812 06:20:32.915259 25091 log.cc:1079] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/290dbf5fcbe243ffa027795750ed71f6/wal-000000026 (ops 125-129)
I20260812 06:20:32.943604 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: LogGCOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.029s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:20:32.944271 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling UndoDeltaBlockGCOp(290dbf5fcbe243ffa027795750ed71f6): 492 bytes on disk
I20260812 06:20:32.944814 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: UndoDeltaBlockGCOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4}
I20260812 06:20:32.945410 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6): perf score=6.157687
I20260812 06:20:32.967520 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.022s	user 0.001s	sys 0.018s Metrics: {"bytes_written":7876885,"delete_count":0,"lbm_write_time_us":9816,"lbm_writes_lt_1ms":195,"reinsert_count":0,"update_count":960}
I20260812 06:20:32.968258 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling MajorDeltaCompactionOp(290dbf5fcbe243ffa027795750ed71f6): perf score=1.000000
I20260812 06:20:33.192271 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: MajorDeltaCompactionOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.224s	user 0.140s	sys 0.084s Metrics: {"cfile_cache_miss":725,"cfile_cache_miss_bytes":32651438,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":364,"lbm_read_time_us":16866,"lbm_reads_lt_1ms":761,"lbm_write_time_us":40574,"lbm_writes_lt_1ms":735,"mutex_wait_us":51,"peak_mem_usage":86600380,"reinsert_count":0,"spinlock_wait_cycles":20480,"thread_start_us":82,"threads_started":1,"update_count":3460}
I20260812 06:20:33.193254 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6): perf score=15.087375
I20260812 06:20:33.240160 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.047s	user 0.026s	sys 0.017s Metrics: {"bytes_written":16738101,"delete_count":0,"lbm_write_time_us":20862,"lbm_writes_lt_1ms":411,"reinsert_count":0,"update_count":2040}
I20260812 06:20:33.240770 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6): perf score=2.188937
I20260812 06:20:33.258947 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.018s	user 0.011s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6324,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:33.259727 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling MajorDeltaCompactionOp(290dbf5fcbe243ffa027795750ed71f6): perf score=1.000000
I20260812 06:20:33.649747 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: MajorDeltaCompactionOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.390s	user 0.265s	sys 0.107s Metrics: {"cfile_cache_miss":540,"cfile_cache_miss_bytes":25102888,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1744,"lbm_read_time_us":28456,"lbm_reads_lt_1ms":580,"lbm_write_time_us":75159,"lbm_writes_lt_1ms":551,"mutex_wait_us":647,"peak_mem_usage":63444180,"reinsert_count":0,"spinlock_wait_cycles":9088,"update_count":2540}
I20260812 06:20:33.651129 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6): perf score=14.095187
I20260812 06:20:33.831490 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.180s	user 0.088s	sys 0.076s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":69252,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:33.833312 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6): perf score=2.188937
I20260812 06:20:33.860013 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.026s	user 0.018s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":10975,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:33.861078 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling MajorDeltaCompactionOp(290dbf5fcbe243ffa027795750ed71f6): perf score=1.000000
I20260812 06:20:34.215655 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: MajorDeltaCompactionOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.354s	user 0.217s	sys 0.129s 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":719,"lbm_read_time_us":31327,"lbm_reads_lt_1ms":572,"lbm_write_time_us":69409,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"thread_start_us":467,"threads_started":6,"update_count":2500}
I20260812 06:20:34.216329 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6): perf score=14.095187
I20260812 06:20:34.285658 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.069s	user 0.032s	sys 0.036s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":27580,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:34.286314 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6): perf score=2.188937
I20260812 06:20:34.298394 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.012s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4493,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:34.298924 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling MajorDeltaCompactionOp(290dbf5fcbe243ffa027795750ed71f6): perf score=1.000000
I20260812 06:20:34.504055 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: MajorDeltaCompactionOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.205s	user 0.139s	sys 0.053s 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":746,"lbm_read_time_us":13447,"lbm_reads_lt_1ms":572,"lbm_write_time_us":36262,"lbm_writes_lt_1ms":543,"mutex_wait_us":57,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10752,"update_count":2500}
I20260812 06:20:34.504864 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6): perf score=14.095187
I20260812 06:20:34.557356 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.052s	user 0.035s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":26808,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:20:34.557905 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6): perf score=2.188937
I20260812 06:20:34.570245 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4368,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:34.570796 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling MajorDeltaCompactionOp(290dbf5fcbe243ffa027795750ed71f6): perf score=1.000000
I20260812 06:20:34.759044 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: MajorDeltaCompactionOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.188s	user 0.116s	sys 0.068s 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":316,"lbm_read_time_us":12097,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29994,"lbm_writes_lt_1ms":543,"mutex_wait_us":36,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":19968,"update_count":2500}
I20260812 06:20:34.759904 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6): perf score=14.095187
I20260812 06:20:34.828030 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.068s	user 0.028s	sys 0.036s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":31791,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:34.828579 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6): perf score=2.188937
I20260812 06:20:34.841534 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.013s	user 0.005s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4563,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:34.842070 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling MajorDeltaCompactionOp(290dbf5fcbe243ffa027795750ed71f6): perf score=1.000000
I20260812 06:20:35.017675 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: MajorDeltaCompactionOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.175s	user 0.144s	sys 0.020s 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":1872,"lbm_read_time_us":11811,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30783,"lbm_writes_lt_1ms":543,"mutex_wait_us":723,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15872,"update_count":2500}
I20260812 06:20:35.018545 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6): perf score=14.095187
I20260812 06:20:35.081241 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.062s	user 0.048s	sys 0.008s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25606,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:35.081751 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6): perf score=2.188937
I20260812 06:20:35.094342 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.012s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4714,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:35.094846 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling FlushMRSOp(290dbf5fcbe243ffa027795750ed71f6): perf score=1.000000
I20260812 06:20:35.125207 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: FlushMRSOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.030s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":59,"dirs.run_cpu_time_us":226,"dirs.run_wall_time_us":1480,"drs_written":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1628,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:20:35.126011 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling LogGCOp(290dbf5fcbe243ffa027795750ed71f6): free 136728524 bytes of WAL
I20260812 06:20:35.126466 25091 log_reader.cc:385] T 290dbf5fcbe243ffa027795750ed71f6: removed 13 log segments from log reader
I20260812 06:20:35.126573 25091 log.cc:1079] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/290dbf5fcbe243ffa027795750ed71f6/wal-000000027 (ops 130-134)
I20260812 06:20:35.126641 25091 log.cc:1079] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/290dbf5fcbe243ffa027795750ed71f6/wal-000000028 (ops 135-139)
I20260812 06:20:35.126698 25091 log.cc:1079] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/290dbf5fcbe243ffa027795750ed71f6/wal-000000029 (ops 140-144)
I20260812 06:20:35.126739 25091 log.cc:1079] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/290dbf5fcbe243ffa027795750ed71f6/wal-000000030 (ops 145-149)
I20260812 06:20:35.126780 25091 log.cc:1079] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/290dbf5fcbe243ffa027795750ed71f6/wal-000000031 (ops 150-154)
I20260812 06:20:35.126816 25091 log.cc:1079] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/290dbf5fcbe243ffa027795750ed71f6/wal-000000032 (ops 155-159)
I20260812 06:20:35.126852 25091 log.cc:1079] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/290dbf5fcbe243ffa027795750ed71f6/wal-000000033 (ops 160-164)
I20260812 06:20:35.126901 25091 log.cc:1079] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/290dbf5fcbe243ffa027795750ed71f6/wal-000000034 (ops 165-169)
I20260812 06:20:35.126945 25091 log.cc:1079] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/290dbf5fcbe243ffa027795750ed71f6/wal-000000035 (ops 170-174)
I20260812 06:20:35.126979 25091 log.cc:1079] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/290dbf5fcbe243ffa027795750ed71f6/wal-000000036 (ops 175-179)
I20260812 06:20:35.127012 25091 log.cc:1079] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/290dbf5fcbe243ffa027795750ed71f6/wal-000000037 (ops 180-184)
I20260812 06:20:35.127035 25091 log.cc:1079] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/290dbf5fcbe243ffa027795750ed71f6/wal-000000038 (ops 185-189)
I20260812 06:20:35.127058 25091 log.cc:1079] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/290dbf5fcbe243ffa027795750ed71f6/wal-000000039 (ops 190-194)
I20260812 06:20:35.158246 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: LogGCOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.032s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:20:35.158759 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6): perf score=3.181125
I20260812 06:20:35.186676 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.028s	user 0.016s	sys 0.010s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":7009,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:35.187211 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling UndoDeltaBlockGCOp(290dbf5fcbe243ffa027795750ed71f6): 494 bytes on disk
I20260812 06:20:35.187659 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: UndoDeltaBlockGCOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4}
I20260812 06:20:35.188169 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6): perf score=2.188937
I20260812 06:20:35.198875 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: FlushDeltaMemStoresOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3843,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:35.199378 25199 maintenance_manager.cc:419] P 4ffafb558e224cebba5aca5acfb114e0: Scheduling MajorDeltaCompactionOp(290dbf5fcbe243ffa027795750ed71f6): perf score=1.000000
I20260812 06:20:35.308161 24927 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.618s	user 2.026s	sys 0.214s
I20260812 06:20:35.466791 24927 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.158s	user 0.002s	sys 0.000s
I20260812 06:20:35.467446 24927 tablet_server.cc:179] TabletServer@127.24.87.193:0 shutting down...
I20260812 06:20:35.481273 25091 maintenance_manager.cc:643] P 4ffafb558e224cebba5aca5acfb114e0: MajorDeltaCompactionOp(290dbf5fcbe243ffa027795750ed71f6) complete. Timing: real 0.282s	user 0.211s	sys 0.070s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979736,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":949,"lbm_read_time_us":16184,"lbm_reads_lt_1ms":770,"lbm_write_time_us":49526,"lbm_writes_lt_1ms":743,"mutex_wait_us":2,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":25344,"thread_start_us":78,"threads_started":1,"update_count":3500}
I20260812 06:20:35.481963 24927 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:35.482362 24927 tablet_replica.cc:333] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0: stopping tablet replica
I20260812 06:20:35.482614 24927 raft_consensus.cc:2243] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:35.482815 24927 raft_consensus.cc:2272] T 290dbf5fcbe243ffa027795750ed71f6 P 4ffafb558e224cebba5aca5acfb114e0 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:35.499773 24927 tablet_server.cc:196] TabletServer@127.24.87.193:0 shutdown complete.
I20260812 06:20:35.539579 24927 master.cc:562] Master@127.24.87.254:43257 shutting down...
I20260812 06:20:35.543478 24927 raft_consensus.cc:2243] T 00000000000000000000000000000000 P ea6db02d47db4c8d8ed3db0424d7b3f2 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:35.543699 24927 raft_consensus.cc:2272] T 00000000000000000000000000000000 P ea6db02d47db4c8d8ed3db0424d7b3f2 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:35.543804 24927 tablet_replica.cc:333] T 00000000000000000000000000000000 P ea6db02d47db4c8d8ed3db0424d7b3f2: stopping tablet replica
I20260812 06:20:35.556331 24927 master.cc:584] Master@127.24.87.254:43257 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (6247 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:20:35.653151 24927 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.24.87.254:45161
I20260812 06:20:35.653584 24927 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:35.656437 25259 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:35.656505 25260 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:35.656517 24927 server_base.cc:1061] running on GCE node
W20260812 06:20:35.656668 25262 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:35.656930 24927 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:35.656983 24927 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:35.657001 24927 hybrid_clock.cc:648] HybridClock initialized: now 1786515635657000 us; error 0 us; skew 500 ppm
I20260812 06:20:35.657897 24927 webserver.cc:533] Webserver started at http://127.24.87.254:45393/ using document root <none> and password file <none>
I20260812 06:20:35.658078 24927 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:35.658154 24927 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:35.658259 24927 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:35.658668 24927 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515629383304-24927-0/minicluster-data/master-0-root/instance:
uuid: "61f28e749be74bc2bbbef32cc955a1dd"
format_stamp: "Formatted at 2026-08-12 06:20:35 on dist-test-slave-3h5h"
I20260812 06:20:35.660403 24927 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:35.661545 25270 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:35.661785 24927 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.000s
I20260812 06:20:35.661875 24927 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515629383304-24927-0/minicluster-data/master-0-root
uuid: "61f28e749be74bc2bbbef32cc955a1dd"
format_stamp: "Formatted at 2026-08-12 06:20:35 on dist-test-slave-3h5h"
I20260812 06:20:35.661964 24927 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515629383304-24927-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515629383304-24927-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515629383304-24927-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:35.672791 24927 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:35.673238 24927 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:35.677275 24927 rpc_server.cc:307] RPC server started. Bound to: 127.24.87.254:45161
I20260812 06:20:35.678543 25357 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.24.87.254:45161 every 8 connection(s)
I20260812 06:20:35.679265 25360 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:35.683449 25360 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 61f28e749be74bc2bbbef32cc955a1dd: Bootstrap starting.
I20260812 06:20:35.684182 25360 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 61f28e749be74bc2bbbef32cc955a1dd: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:35.685218 25360 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 61f28e749be74bc2bbbef32cc955a1dd: No bootstrap required, opened a new log
I20260812 06:20:35.685561 25360 raft_consensus.cc:359] T 00000000000000000000000000000000 P 61f28e749be74bc2bbbef32cc955a1dd [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "61f28e749be74bc2bbbef32cc955a1dd" member_type: VOTER }
I20260812 06:20:35.685642 25360 raft_consensus.cc:385] T 00000000000000000000000000000000 P 61f28e749be74bc2bbbef32cc955a1dd [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:35.685665 25360 raft_consensus.cc:740] T 00000000000000000000000000000000 P 61f28e749be74bc2bbbef32cc955a1dd [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 61f28e749be74bc2bbbef32cc955a1dd, State: Initialized, Role: FOLLOWER
I20260812 06:20:35.685781 25360 consensus_queue.cc:260] T 00000000000000000000000000000000 P 61f28e749be74bc2bbbef32cc955a1dd [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: "61f28e749be74bc2bbbef32cc955a1dd" member_type: VOTER }
I20260812 06:20:35.685845 25360 raft_consensus.cc:399] T 00000000000000000000000000000000 P 61f28e749be74bc2bbbef32cc955a1dd [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:35.685869 25360 raft_consensus.cc:493] T 00000000000000000000000000000000 P 61f28e749be74bc2bbbef32cc955a1dd [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:35.685899 25360 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 61f28e749be74bc2bbbef32cc955a1dd [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:35.686515 25360 raft_consensus.cc:515] T 00000000000000000000000000000000 P 61f28e749be74bc2bbbef32cc955a1dd [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "61f28e749be74bc2bbbef32cc955a1dd" member_type: VOTER }
I20260812 06:20:35.686625 25360 leader_election.cc:304] T 00000000000000000000000000000000 P 61f28e749be74bc2bbbef32cc955a1dd [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: 61f28e749be74bc2bbbef32cc955a1dd; no voters: 
I20260812 06:20:35.686765 25360 leader_election.cc:290] T 00000000000000000000000000000000 P 61f28e749be74bc2bbbef32cc955a1dd [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:35.686889 25364 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 61f28e749be74bc2bbbef32cc955a1dd [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:35.687121 25364 raft_consensus.cc:697] T 00000000000000000000000000000000 P 61f28e749be74bc2bbbef32cc955a1dd [term 1 LEADER]: Becoming Leader. State: Replica: 61f28e749be74bc2bbbef32cc955a1dd, State: Running, Role: LEADER
I20260812 06:20:35.687263 25364 consensus_queue.cc:237] T 00000000000000000000000000000000 P 61f28e749be74bc2bbbef32cc955a1dd [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: "61f28e749be74bc2bbbef32cc955a1dd" member_type: VOTER }
I20260812 06:20:35.687289 25360 sys_catalog.cc:565] T 00000000000000000000000000000000 P 61f28e749be74bc2bbbef32cc955a1dd [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:35.687707 25365 sys_catalog.cc:455] T 00000000000000000000000000000000 P 61f28e749be74bc2bbbef32cc955a1dd [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "61f28e749be74bc2bbbef32cc955a1dd" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "61f28e749be74bc2bbbef32cc955a1dd" member_type: VOTER } }
I20260812 06:20:35.687822 25365 sys_catalog.cc:458] T 00000000000000000000000000000000 P 61f28e749be74bc2bbbef32cc955a1dd [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:35.687706 25366 sys_catalog.cc:455] T 00000000000000000000000000000000 P 61f28e749be74bc2bbbef32cc955a1dd [sys.catalog]: SysCatalogTable state changed. Reason: New leader 61f28e749be74bc2bbbef32cc955a1dd. Latest consensus state: current_term: 1 leader_uuid: "61f28e749be74bc2bbbef32cc955a1dd" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "61f28e749be74bc2bbbef32cc955a1dd" member_type: VOTER } }
I20260812 06:20:35.687958 25366 sys_catalog.cc:458] T 00000000000000000000000000000000 P 61f28e749be74bc2bbbef32cc955a1dd [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:35.688144 25370 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:35.689009 25370 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:35.689294 24927 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:35.690869 25370 catalog_manager.cc:1383] Generated new cluster ID: d71a4076149441469a363fc12950b25f
I20260812 06:20:35.690938 25370 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:35.700578 25370 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:35.701241 25370 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:35.709714 25370 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 61f28e749be74bc2bbbef32cc955a1dd: Generated new TSK 0
I20260812 06:20:35.709957 25370 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:35.721640 24927 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:35.723872 25399 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:35.723923 24927 server_base.cc:1061] running on GCE node
W20260812 06:20:35.724045 25395 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:35.723992 25397 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:35.724371 24927 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:35.724417 24927 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:35.724433 24927 hybrid_clock.cc:648] HybridClock initialized: now 1786515635724433 us; error 0 us; skew 500 ppm
I20260812 06:20:35.725288 24927 webserver.cc:533] Webserver started at http://127.24.87.193:34323/ using document root <none> and password file <none>
I20260812 06:20:35.725427 24927 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:35.725471 24927 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:35.725528 24927 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:35.725872 24927 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515629383304-24927-0/minicluster-data/ts-0-root/instance:
uuid: "fa343495c16847759d0b58196b167606"
format_stamp: "Formatted at 2026-08-12 06:20:35 on dist-test-slave-3h5h"
I20260812 06:20:35.727314 24927 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:35.728392 25405 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:35.728720 24927 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:35.728801 24927 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515629383304-24927-0/minicluster-data/ts-0-root
uuid: "fa343495c16847759d0b58196b167606"
format_stamp: "Formatted at 2026-08-12 06:20:35 on dist-test-slave-3h5h"
I20260812 06:20:35.728909 24927 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515629383304-24927-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515629383304-24927-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515629383304-24927-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:35.769244 24927 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:35.769685 24927 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:35.770038 24927 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:35.770552 24927 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:35.770617 24927 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:35.770677 24927 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:35.770731 24927 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:35.775328 24927 rpc_server.cc:307] RPC server started. Bound to: 127.24.87.193:40815
I20260812 06:20:35.777132 25499 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.24.87.193:40815 every 8 connection(s)
I20260812 06:20:35.781867 25501 heartbeater.cc:344] Connected to a master server at 127.24.87.254:45161
I20260812 06:20:35.781987 25501 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:35.782195 25501 heartbeater.cc:507] Master 127.24.87.254:45161 requested a full tablet report, sending...
I20260812 06:20:35.782888 25297 ts_manager.cc:194] Registered new tserver with Master: fa343495c16847759d0b58196b167606 (127.24.87.193:40815)
I20260812 06:20:35.782980 24927 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.006706277s
I20260812 06:20:35.783910 25297 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:40348
I20260812 06:20:35.790550 25297 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:40350:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:20:35.800098 25445 tablet_service.cc:1511] Processing CreateTablet for tablet 5d89293312f84b7b935abf73805252d1 (DEFAULT_TABLE table=heavy-update-compaction-test [id=0a26492d42df499ca1821932cfc70f75]), partition=
I20260812 06:20:35.800405 25445 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 5d89293312f84b7b935abf73805252d1. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:35.802778 25517 tablet_bootstrap.cc:492] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606: Bootstrap starting.
I20260812 06:20:35.803654 25517 tablet_bootstrap.cc:654] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:35.805003 25517 tablet_bootstrap.cc:492] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606: No bootstrap required, opened a new log
I20260812 06:20:35.805099 25517 ts_tablet_manager.cc:1403] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:35.805598 25517 raft_consensus.cc:359] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fa343495c16847759d0b58196b167606" member_type: VOTER last_known_addr { host: "127.24.87.193" port: 40815 } }
I20260812 06:20:35.805691 25517 raft_consensus.cc:385] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:35.805716 25517 raft_consensus.cc:740] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: fa343495c16847759d0b58196b167606, State: Initialized, Role: FOLLOWER
I20260812 06:20:35.805809 25517 consensus_queue.cc:260] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606 [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: "fa343495c16847759d0b58196b167606" member_type: VOTER last_known_addr { host: "127.24.87.193" port: 40815 } }
I20260812 06:20:35.805866 25517 raft_consensus.cc:399] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:35.805889 25517 raft_consensus.cc:493] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:35.805918 25517 raft_consensus.cc:3060] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:35.806617 25517 raft_consensus.cc:515] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fa343495c16847759d0b58196b167606" member_type: VOTER last_known_addr { host: "127.24.87.193" port: 40815 } }
I20260812 06:20:35.806747 25517 leader_election.cc:304] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606 [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: fa343495c16847759d0b58196b167606; no voters: 
I20260812 06:20:35.806911 25517 leader_election.cc:290] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:35.807065 25519 raft_consensus.cc:2804] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:35.807266 25517 ts_tablet_manager.cc:1434] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:35.807318 25501 heartbeater.cc:499] Master 127.24.87.254:45161 was elected leader, sending a full tablet report...
I20260812 06:20:35.807318 25519 raft_consensus.cc:697] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606 [term 1 LEADER]: Becoming Leader. State: Replica: fa343495c16847759d0b58196b167606, State: Running, Role: LEADER
I20260812 06:20:35.807516 25519 consensus_queue.cc:237] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606 [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: "fa343495c16847759d0b58196b167606" member_type: VOTER last_known_addr { host: "127.24.87.193" port: 40815 } }
I20260812 06:20:35.808925 25297 catalog_manager.cc:5719] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606 reported cstate change: term changed from 0 to 1, leader changed from <none> to fa343495c16847759d0b58196b167606 (127.24.87.193). New cstate: current_term: 1 leader_uuid: "fa343495c16847759d0b58196b167606" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fa343495c16847759d0b58196b167606" member_type: VOTER last_known_addr { host: "127.24.87.193" port: 40815 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:35.870285 24927 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.055s	user 0.013s	sys 0.011s
I20260812 06:20:36.027724 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling FlushMRSOp(5d89293312f84b7b935abf73805252d1): perf score=19.054940
I20260812 06:20:36.217732 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: FlushMRSOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.190s	user 0.144s	sys 0.039s Metrics: {"bytes_written":12717738,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":112,"dirs.run_cpu_time_us":220,"dirs.run_wall_time_us":1023,"drs_written":1,"lbm_read_time_us":136,"lbm_reads_lt_1ms":4,"lbm_write_time_us":47200,"lbm_writes_lt_1ms":867,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":768,"update_count":1550}
I20260812 06:20:36.218786 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling LogGCOp(5d89293312f84b7b935abf73805252d1): free 20743880 bytes of WAL
I20260812 06:20:36.219099 25413 log_reader.cc:385] T 5d89293312f84b7b935abf73805252d1: removed 2 log segments from log reader
I20260812 06:20:36.219167 25413 log.cc:1079] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/5d89293312f84b7b935abf73805252d1/wal-000000001 (ops 1-6)
I20260812 06:20:36.219235 25413 log.cc:1079] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/5d89293312f84b7b935abf73805252d1/wal-000000002 (ops 7-11)
I20260812 06:20:36.224313 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: LogGCOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.005s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:20:36.224802 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling UndoDeltaBlockGCOp(5d89293312f84b7b935abf73805252d1): 20513801 bytes on disk
I20260812 06:20:36.225410 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: UndoDeltaBlockGCOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":109,"lbm_reads_lt_1ms":4}
I20260812 06:20:36.225889 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1): perf score=2.188937
I20260812 06:20:36.243160 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.017s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4070,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:36.243763 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling MajorDeltaCompactionOp(5d89293312f84b7b935abf73805252d1): perf score=1.000000
I20260812 06:20:36.399138 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: MajorDeltaCompactionOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.155s	user 0.101s	sys 0.053s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672271,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1066,"lbm_read_time_us":10848,"lbm_reads_lt_1ms":460,"lbm_write_time_us":24983,"lbm_writes_lt_1ms":443,"mutex_wait_us":92,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6272,"thread_start_us":402,"threads_started":5,"update_count":2000}
I20260812 06:20:36.399833 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1): perf score=12.110812
I20260812 06:20:36.451849 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.052s	user 0.024s	sys 0.020s Metrics: {"bytes_written":13948451,"delete_count":0,"lbm_write_time_us":20214,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":342,"reinsert_count":0,"update_count":1700}
I20260812 06:20:36.452454 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1): perf score=1.196750
I20260812 06:20:36.468538 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.016s	user 0.007s	sys 0.004s Metrics: {"bytes_written":2871909,"delete_count":0,"lbm_write_time_us":4466,"lbm_writes_lt_1ms":73,"reinsert_count":0,"update_count":350}
I20260812 06:20:36.469070 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1): perf score=2.188937
I20260812 06:20:36.478567 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.009s	user 0.002s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3453,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:36.479038 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling MajorDeltaCompactionOp(5d89293312f84b7b935abf73805252d1): perf score=1.000000
I20260812 06:20:36.657980 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: MajorDeltaCompactionOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.179s	user 0.118s	sys 0.060s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774765,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":172,"lbm_read_time_us":13059,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30238,"lbm_writes_lt_1ms":543,"mutex_wait_us":72,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2500}
I20260812 06:20:36.658756 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1): perf score=11.118625
I20260812 06:20:36.705024 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.046s	user 0.019s	sys 0.027s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":15222,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:36.705746 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1): perf score=2.188937
I20260812 06:20:36.722152 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.016s	user 0.006s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6211,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:36.722607 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling MajorDeltaCompactionOp(5d89293312f84b7b935abf73805252d1): perf score=1.000000
I20260812 06:20:36.875203 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: MajorDeltaCompactionOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.152s	user 0.096s	sys 0.050s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672269,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":565,"lbm_read_time_us":10688,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22005,"lbm_writes_lt_1ms":443,"mutex_wait_us":274,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:36.875777 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1): perf score=11.118625
I20260812 06:20:36.911314 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.035s	user 0.028s	sys 0.004s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15383,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:36.912164 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1): perf score=2.188937
I20260812 06:20:36.927069 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.015s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4847,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:36.927476 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling MajorDeltaCompactionOp(5d89293312f84b7b935abf73805252d1): perf score=1.000000
I20260812 06:20:37.057695 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: MajorDeltaCompactionOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.130s	user 0.110s	sys 0.019s 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":833,"lbm_read_time_us":7398,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25587,"lbm_writes_lt_1ms":443,"mutex_wait_us":478,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8960,"update_count":2000}
I20260812 06:20:37.058339 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1): perf score=10.126437
I20260812 06:20:37.092070 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.033s	user 0.021s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13570,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:37.092687 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1): perf score=2.188937
I20260812 06:20:37.105558 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.013s	user 0.003s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4443,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:37.106133 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling MajorDeltaCompactionOp(5d89293312f84b7b935abf73805252d1): perf score=1.000000
I20260812 06:20:37.235133 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: MajorDeltaCompactionOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.129s	user 0.110s	sys 0.019s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":916,"lbm_read_time_us":9895,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23735,"lbm_writes_lt_1ms":443,"mutex_wait_us":305,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8320,"update_count":2000}
I20260812 06:20:37.235735 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1): perf score=10.126437
I20260812 06:20:37.275707 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.040s	user 0.020s	sys 0.017s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":15615,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:37.276221 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1): perf score=2.188937
I20260812 06:20:37.287236 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.011s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3989,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:37.287685 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling MajorDeltaCompactionOp(5d89293312f84b7b935abf73805252d1): perf score=1.000000
I20260812 06:20:37.409889 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: MajorDeltaCompactionOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.122s	user 0.094s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1976,"lbm_read_time_us":8985,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22833,"lbm_writes_lt_1ms":443,"mutex_wait_us":503,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:37.410575 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1): perf score=10.126437
I20260812 06:20:37.457646 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.047s	user 0.023s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15713,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:37.458231 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1): perf score=2.188937
I20260812 06:20:37.469049 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4157,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:37.470937 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling FlushMRSOp(5d89293312f84b7b935abf73805252d1): perf score=1.000000
I20260812 06:20:37.508572 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: FlushMRSOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.037s	user 0.029s	sys 0.004s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":97,"dirs.run_cpu_time_us":199,"dirs.run_wall_time_us":1574,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1522,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:37.509263 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling LogGCOp(5d89293312f84b7b935abf73805252d1): free 124710249 bytes of WAL
I20260812 06:20:37.509488 25413 log_reader.cc:385] T 5d89293312f84b7b935abf73805252d1: removed 12 log segments from log reader
I20260812 06:20:37.509549 25413 log.cc:1079] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/5d89293312f84b7b935abf73805252d1/wal-000000003 (ops 12-16)
I20260812 06:20:37.509603 25413 log.cc:1079] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/5d89293312f84b7b935abf73805252d1/wal-000000004 (ops 17-21)
I20260812 06:20:37.509662 25413 log.cc:1079] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/5d89293312f84b7b935abf73805252d1/wal-000000005 (ops 22-26)
I20260812 06:20:37.509702 25413 log.cc:1079] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/5d89293312f84b7b935abf73805252d1/wal-000000006 (ops 27-31)
I20260812 06:20:37.509738 25413 log.cc:1079] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/5d89293312f84b7b935abf73805252d1/wal-000000007 (ops 32-36)
I20260812 06:20:37.509776 25413 log.cc:1079] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/5d89293312f84b7b935abf73805252d1/wal-000000008 (ops 37-41)
I20260812 06:20:37.509812 25413 log.cc:1079] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/5d89293312f84b7b935abf73805252d1/wal-000000009 (ops 42-46)
I20260812 06:20:37.509850 25413 log.cc:1079] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/5d89293312f84b7b935abf73805252d1/wal-000000010 (ops 47-51)
I20260812 06:20:37.509884 25413 log.cc:1079] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/5d89293312f84b7b935abf73805252d1/wal-000000011 (ops 52-56)
I20260812 06:20:37.509920 25413 log.cc:1079] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/5d89293312f84b7b935abf73805252d1/wal-000000012 (ops 57-61)
I20260812 06:20:37.509956 25413 log.cc:1079] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/5d89293312f84b7b935abf73805252d1/wal-000000013 (ops 62-66)
I20260812 06:20:37.509992 25413 log.cc:1079] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/5d89293312f84b7b935abf73805252d1/wal-000000014 (ops 67-71)
I20260812 06:20:37.536433 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: LogGCOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.027s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:20:37.537073 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling UndoDeltaBlockGCOp(5d89293312f84b7b935abf73805252d1): 473 bytes on disk
I20260812 06:20:37.537549 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: UndoDeltaBlockGCOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:20:37.538009 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1): perf score=3.181125
I20260812 06:20:37.552379 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.014s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4368,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:37.552875 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1): perf score=2.188937
I20260812 06:20:37.562332 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.009s	user 0.007s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3443,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:37.562831 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling MajorDeltaCompactionOp(5d89293312f84b7b935abf73805252d1): perf score=1.000000
I20260812 06:20:37.775499 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: MajorDeltaCompactionOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.212s	user 0.113s	sys 0.097s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877326,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":634,"lbm_read_time_us":13868,"lbm_reads_lt_1ms":674,"lbm_write_time_us":35943,"lbm_writes_lt_1ms":643,"mutex_wait_us":66,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":54656,"thread_start_us":99,"threads_started":1,"update_count":3000}
I20260812 06:20:37.776187 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1): perf score=14.095187
I20260812 06:20:37.842672 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.066s	user 0.029s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23664,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:37.843266 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1): perf score=2.188937
I20260812 06:20:37.858860 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5680,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:37.859459 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling MajorDeltaCompactionOp(5d89293312f84b7b935abf73805252d1): perf score=1.000000
I20260812 06:20:38.044281 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: MajorDeltaCompactionOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.185s	user 0.112s	sys 0.072s 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":379,"lbm_read_time_us":13983,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29492,"lbm_writes_lt_1ms":543,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":44928,"update_count":2500}
I20260812 06:20:38.044979 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1): perf score=14.095187
I20260812 06:20:38.102468 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.057s	user 0.027s	sys 0.029s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25997,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:20:38.103214 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1): perf score=2.188937
I20260812 06:20:38.123435 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.019s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6283,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:38.123921 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling MajorDeltaCompactionOp(5d89293312f84b7b935abf73805252d1): perf score=1.000000
I20260812 06:20:38.308449 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: MajorDeltaCompactionOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.184s	user 0.134s	sys 0.049s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1035,"lbm_read_time_us":12062,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31542,"lbm_writes_lt_1ms":543,"mutex_wait_us":276,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8448,"update_count":2500}
I20260812 06:20:38.309144 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1): perf score=15.087375
I20260812 06:20:38.367859 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.059s	user 0.030s	sys 0.024s Metrics: {"bytes_written":16820144,"delete_count":0,"lbm_write_time_us":20684,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:20:38.368618 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1): perf score=3.181125
I20260812 06:20:38.382838 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":5087238,"delete_count":0,"lbm_write_time_us":5914,"lbm_writes_lt_1ms":127,"reinsert_count":0,"update_count":620}
I20260812 06:20:38.383303 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1): perf score=1.196750
I20260812 06:20:38.391847 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.008s	user 0.007s	sys 0.000s Metrics: {"bytes_written":2707805,"delete_count":0,"lbm_write_time_us":3113,"lbm_writes_lt_1ms":69,"reinsert_count":0,"update_count":330}
I20260812 06:20:38.392783 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling MajorDeltaCompactionOp(5d89293312f84b7b935abf73805252d1): perf score=1.000000
I20260812 06:20:38.594898 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: MajorDeltaCompactionOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.202s	user 0.130s	sys 0.069s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877187,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":429,"lbm_read_time_us":14001,"lbm_reads_lt_1ms":673,"lbm_write_time_us":33631,"lbm_writes_lt_1ms":643,"mutex_wait_us":92,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3072,"update_count":3000}
I20260812 06:20:38.595572 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1): perf score=16.079562
I20260812 06:20:38.649197 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.053s	user 0.038s	sys 0.015s Metrics: {"bytes_written":17845747,"delete_count":0,"lbm_write_time_us":23894,"lbm_writes_lt_1ms":438,"reinsert_count":0,"update_count":2175}
I20260812 06:20:38.649674 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1): perf score=1.196750
I20260812 06:20:38.671470 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.022s	user 0.006s	sys 0.001s Metrics: {"bytes_written":2666779,"delete_count":0,"lbm_write_time_us":3029,"lbm_writes_lt_1ms":68,"reinsert_count":0,"update_count":325}
I20260812 06:20:38.671990 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1): perf score=2.188937
I20260812 06:20:38.686442 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.014s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5567,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:38.686949 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling MajorDeltaCompactionOp(5d89293312f84b7b935abf73805252d1): perf score=1.000000
I20260812 06:20:38.896045 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: MajorDeltaCompactionOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.209s	user 0.153s	sys 0.055s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877184,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1092,"lbm_read_time_us":13091,"lbm_reads_lt_1ms":673,"lbm_write_time_us":36141,"lbm_writes_lt_1ms":643,"mutex_wait_us":358,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":47744,"update_count":3000}
I20260812 06:20:38.896966 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1): perf score=14.095187
I20260812 06:20:38.966593 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.069s	user 0.031s	sys 0.020s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":23166,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:38.967216 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1): perf score=2.188937
I20260812 06:20:38.982165 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5485,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:38.982662 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling FlushMRSOp(5d89293312f84b7b935abf73805252d1): perf score=1.000000
I20260812 06:20:39.013602 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: FlushMRSOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.031s	user 0.023s	sys 0.004s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":86,"dirs.run_cpu_time_us":267,"dirs.run_wall_time_us":1589,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1670,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:39.014348 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling LogGCOp(5d89293312f84b7b935abf73805252d1): free 112239328 bytes of WAL
I20260812 06:20:39.014617 25413 log_reader.cc:385] T 5d89293312f84b7b935abf73805252d1: removed 11 log segments from log reader
I20260812 06:20:39.014668 25413 log.cc:1079] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/5d89293312f84b7b935abf73805252d1/wal-000000015 (ops 72-76)
I20260812 06:20:39.014753 25413 log.cc:1079] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/5d89293312f84b7b935abf73805252d1/wal-000000016 (ops 77-81)
I20260812 06:20:39.014801 25413 log.cc:1079] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/5d89293312f84b7b935abf73805252d1/wal-000000017 (ops 82-86)
I20260812 06:20:39.014820 25413 log.cc:1079] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/5d89293312f84b7b935abf73805252d1/wal-000000018 (ops 87-91)
I20260812 06:20:39.014876 25413 log.cc:1079] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/5d89293312f84b7b935abf73805252d1/wal-000000019 (ops 92-96)
I20260812 06:20:39.014946 25413 log.cc:1079] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/5d89293312f84b7b935abf73805252d1/wal-000000020 (ops 97-100)
I20260812 06:20:39.014986 25413 log.cc:1079] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/5d89293312f84b7b935abf73805252d1/wal-000000021 (ops 101-105)
I20260812 06:20:39.015029 25413 log.cc:1079] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/5d89293312f84b7b935abf73805252d1/wal-000000022 (ops 106-110)
I20260812 06:20:39.015064 25413 log.cc:1079] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/5d89293312f84b7b935abf73805252d1/wal-000000023 (ops 111-115)
I20260812 06:20:39.015101 25413 log.cc:1079] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/5d89293312f84b7b935abf73805252d1/wal-000000024 (ops 116-120)
I20260812 06:20:39.015141 25413 log.cc:1079] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/5d89293312f84b7b935abf73805252d1/wal-000000025 (ops 121-125)
I20260812 06:20:39.038278 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: LogGCOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.024s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:20:39.038756 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1): perf score=2.188937
I20260812 06:20:39.061452 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.023s	user 0.016s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6473,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:39.061895 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1): perf score=2.188937
I20260812 06:20:39.072533 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4059,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:39.073029 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling UndoDeltaBlockGCOp(5d89293312f84b7b935abf73805252d1): 462 bytes on disk
I20260812 06:20:39.073612 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: UndoDeltaBlockGCOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":95,"lbm_reads_lt_1ms":4}
I20260812 06:20:39.074525 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling MajorDeltaCompactionOp(5d89293312f84b7b935abf73805252d1): perf score=1.000000
I20260812 06:20:39.309163 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: MajorDeltaCompactionOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.234s	user 0.138s	sys 0.083s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979749,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":47,"lbm_read_time_us":15503,"lbm_reads_lt_1ms":774,"lbm_write_time_us":39902,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"thread_start_us":82,"threads_started":1,"update_count":3500}
I20260812 06:20:39.309790 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1): perf score=18.063937
I20260812 06:20:39.377734 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.068s	user 0.029s	sys 0.034s Metrics: {"bytes_written":20512319,"delete_count":0,"lbm_write_time_us":32622,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:20:39.378334 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1): perf score=2.188937
I20260812 06:20:39.394899 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.016s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6255,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:39.395475 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling MajorDeltaCompactionOp(5d89293312f84b7b935abf73805252d1): perf score=1.000000
I20260812 06:20:39.583227 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: MajorDeltaCompactionOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.188s	user 0.152s	sys 0.036s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877105,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":329,"lbm_read_time_us":10346,"lbm_reads_lt_1ms":664,"lbm_write_time_us":38728,"lbm_writes_lt_1ms":643,"mutex_wait_us":58,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":3000}
I20260812 06:20:39.583843 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1): perf score=14.095187
I20260812 06:20:39.643285 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.059s	user 0.029s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22513,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:39.643832 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1): perf score=2.188937
I20260812 06:20:39.659723 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.016s	user 0.002s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5953,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:39.660573 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling MajorDeltaCompactionOp(5d89293312f84b7b935abf73805252d1): perf score=1.000000
I20260812 06:20:39.811293 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: MajorDeltaCompactionOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.150s	user 0.108s	sys 0.040s 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":909,"lbm_read_time_us":11724,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27427,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11520,"update_count":2500}
I20260812 06:20:39.812783 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1): perf score=12.110812
I20260812 06:20:39.859282 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.046s	user 0.026s	sys 0.014s Metrics: {"bytes_written":13825386,"delete_count":0,"lbm_write_time_us":19004,"lbm_writes_lt_1ms":340,"reinsert_count":0,"update_count":1685}
I20260812 06:20:39.859838 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1): perf score=1.196750
I20260812 06:20:39.876194 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.016s	user 0.003s	sys 0.004s Metrics: {"bytes_written":2994987,"delete_count":0,"lbm_write_time_us":3179,"lbm_writes_lt_1ms":76,"reinsert_count":0,"update_count":365}
I20260812 06:20:39.876746 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1): perf score=2.188937
I20260812 06:20:39.886431 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.009s	user 0.007s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3483,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:39.886996 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling MajorDeltaCompactionOp(5d89293312f84b7b935abf73805252d1): perf score=1.000000
I20260812 06:20:40.074191 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: MajorDeltaCompactionOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.187s	user 0.117s	sys 0.067s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774778,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":693,"lbm_read_time_us":12168,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30352,"lbm_writes_lt_1ms":543,"mutex_wait_us":46,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":57728,"update_count":2500}
I20260812 06:20:40.075023 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1): perf score=14.095187
I20260812 06:20:40.127852 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.053s	user 0.042s	sys 0.008s Metrics: {"bytes_written":16409897,"delete_count":0,"lbm_write_time_us":23702,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:40.128341 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling MajorDeltaCompactionOp(5d89293312f84b7b935abf73805252d1): perf score=1.000000
I20260812 06:20:40.272953 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: MajorDeltaCompactionOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.144s	user 0.086s	sys 0.056s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672153,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1425,"lbm_read_time_us":8869,"lbm_reads_lt_1ms":463,"lbm_write_time_us":25383,"lbm_writes_lt_1ms":443,"mutex_wait_us":285,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:40.273788 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1): perf score=11.118625
I20260812 06:20:40.333561 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.060s	user 0.038s	sys 0.008s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":20490,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:40.334079 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1): perf score=6.157687
I20260812 06:20:40.353541 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.019s	user 0.019s	sys 0.000s Metrics: {"bytes_written":7794838,"delete_count":0,"lbm_write_time_us":8164,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:20:40.354061 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling MajorDeltaCompactionOp(5d89293312f84b7b935abf73805252d1): perf score=1.000000
I20260812 06:20:40.539232 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: MajorDeltaCompactionOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.185s	user 0.122s	sys 0.057s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774696,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1084,"lbm_read_time_us":10583,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31897,"lbm_writes_lt_1ms":543,"mutex_wait_us":321,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2500}
I20260812 06:20:40.539978 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1): perf score=14.095187
I20260812 06:20:40.588102 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.048s	user 0.030s	sys 0.014s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22730,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:40.588742 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1): perf score=2.188937
I20260812 06:20:40.602202 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.013s	user 0.003s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5387,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:40.602788 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling FlushMRSOp(5d89293312f84b7b935abf73805252d1): perf score=1.000000
I20260812 06:20:40.639637 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: FlushMRSOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.037s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1357582,"cfile_init":1,"dirs.queue_time_us":102,"dirs.run_cpu_time_us":329,"dirs.run_wall_time_us":1790,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2063,"lbm_writes_lt_1ms":44,"peak_mem_usage":0,"rows_written":33}
I20260812 06:20:40.640753 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling LogGCOp(5d89293312f84b7b935abf73805252d1): free 141338724 bytes of WAL
I20260812 06:20:40.641052 25413 log_reader.cc:385] T 5d89293312f84b7b935abf73805252d1: removed 14 log segments from log reader
I20260812 06:20:40.641109 25413 log.cc:1079] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/5d89293312f84b7b935abf73805252d1/wal-000000026 (ops 126-130)
I20260812 06:20:40.641151 25413 log.cc:1079] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/5d89293312f84b7b935abf73805252d1/wal-000000027 (ops 131-134)
I20260812 06:20:40.641203 25413 log.cc:1079] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/5d89293312f84b7b935abf73805252d1/wal-000000028 (ops 135-139)
I20260812 06:20:40.641330 25413 log.cc:1079] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/5d89293312f84b7b935abf73805252d1/wal-000000029 (ops 140-144)
I20260812 06:20:40.641395 25413 log.cc:1079] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/5d89293312f84b7b935abf73805252d1/wal-000000030 (ops 145-149)
I20260812 06:20:40.641431 25413 log.cc:1079] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/5d89293312f84b7b935abf73805252d1/wal-000000031 (ops 150-154)
I20260812 06:20:40.641474 25413 log.cc:1079] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/5d89293312f84b7b935abf73805252d1/wal-000000032 (ops 155-159)
I20260812 06:20:40.641520 25413 log.cc:1079] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/5d89293312f84b7b935abf73805252d1/wal-000000033 (ops 160-164)
I20260812 06:20:40.641562 25413 log.cc:1079] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/5d89293312f84b7b935abf73805252d1/wal-000000034 (ops 165-168)
I20260812 06:20:40.641605 25413 log.cc:1079] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/5d89293312f84b7b935abf73805252d1/wal-000000035 (ops 169-173)
I20260812 06:20:40.641708 25413 log.cc:1079] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/5d89293312f84b7b935abf73805252d1/wal-000000036 (ops 174-178)
I20260812 06:20:40.641789 25413 log.cc:1079] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/5d89293312f84b7b935abf73805252d1/wal-000000037 (ops 179-183)
I20260812 06:20:40.641851 25413 log.cc:1079] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/5d89293312f84b7b935abf73805252d1/wal-000000038 (ops 184-188)
I20260812 06:20:40.641909 25413 log.cc:1079] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606: Deleting log segment in path: /tmp/dist-test-taskBqVH5T/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515629383304-24927-0/minicluster-data/ts-0-root/wals/5d89293312f84b7b935abf73805252d1/wal-000000039 (ops 189-193)
I20260812 06:20:40.675765 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: LogGCOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.035s	user 0.000s	sys 0.032s Metrics: {}
I20260812 06:20:40.676270 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1): perf score=6.157687
I20260812 06:20:40.697464 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.020s	user 0.007s	sys 0.013s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":8871,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:20:40.697922 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling MajorDeltaCompactionOp(5d89293312f84b7b935abf73805252d1): perf score=1.000000
I20260812 06:20:40.817315 24927 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.947s	user 1.825s	sys 0.189s
I20260812 06:20:40.935218 24927 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.117s	user 0.001s	sys 0.000s
I20260812 06:20:40.935812 24927 tablet_server.cc:179] TabletServer@127.24.87.193:0 shutting down...
I20260812 06:20:40.936360 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: MajorDeltaCompactionOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.238s	user 0.154s	sys 0.084s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32979632,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":836,"lbm_read_time_us":17789,"lbm_reads_lt_1ms":765,"lbm_write_time_us":42460,"lbm_writes_lt_1ms":743,"mutex_wait_us":214,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":4736,"thread_start_us":70,"threads_started":1,"update_count":3500}
I20260812 06:20:40.937263 25502 maintenance_manager.cc:419] P fa343495c16847759d0b58196b167606: Scheduling FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1): perf score=10.126437
I20260812 06:20:40.977622 25413 maintenance_manager.cc:643] P fa343495c16847759d0b58196b167606: FlushDeltaMemStoresOp(5d89293312f84b7b935abf73805252d1) complete. Timing: real 0.040s	user 0.014s	sys 0.025s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13729,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:40.978315 24927 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:40.978552 24927 tablet_replica.cc:333] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606: stopping tablet replica
I20260812 06:20:40.978735 24927 raft_consensus.cc:2243] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:40.978915 24927 raft_consensus.cc:2272] T 5d89293312f84b7b935abf73805252d1 P fa343495c16847759d0b58196b167606 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:40.994488 24927 tablet_server.cc:196] TabletServer@127.24.87.193:0 shutdown complete.
I20260812 06:20:40.997371 24927 master.cc:562] Master@127.24.87.254:45161 shutting down...
I20260812 06:20:41.000871 24927 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 61f28e749be74bc2bbbef32cc955a1dd [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:41.001042 24927 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 61f28e749be74bc2bbbef32cc955a1dd [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:41.001094 24927 tablet_replica.cc:333] T 00000000000000000000000000000000 P 61f28e749be74bc2bbbef32cc955a1dd: stopping tablet replica
I20260812 06:20:41.014961 24927 master.cc:584] Master@127.24.87.254:45161 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5461 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11709 ms total)

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