[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:19:10.983899  5162 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.5.10.190:44043
I20260812 06:19:10.984946  5162 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:19:10.985562  5162 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:10.992544  5167 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:10.992584  5170 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:10.992831  5168 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:10.992758  5162 server_base.cc:1061] running on GCE node
I20260812 06:19:10.993379  5162 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:10.993502  5162 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:10.993566  5162 hybrid_clock.cc:648] HybridClock initialized: now 1786515550993563 us; error 0 us; skew 500 ppm
I20260812 06:19:10.995461  5162 webserver.cc:533] Webserver started at http://127.5.10.190:35975/ using document root <none> and password file <none>
I20260812 06:19:10.996048  5162 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:10.996142  5162 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:10.996389  5162 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:10.998203  5162 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550972950-5162-0/minicluster-data/master-0-root/instance:
uuid: "3c520b60a6b1456fb9dc3669c8e7f4c7"
format_stamp: "Formatted at 2026-08-12 06:19:10 on dist-test-slave-0kls"
I20260812 06:19:11.002171  5162 fs_manager.cc:696] Time spent creating directory manager: real 0.004s	user 0.004s	sys 0.000s
I20260812 06:19:11.004418  5176 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:11.005489  5162 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:11.005653  5162 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550972950-5162-0/minicluster-data/master-0-root
uuid: "3c520b60a6b1456fb9dc3669c8e7f4c7"
format_stamp: "Formatted at 2026-08-12 06:19:10 on dist-test-slave-0kls"
I20260812 06:19:11.005772  5162 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550972950-5162-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550972950-5162-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550972950-5162-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:11.029613  5162 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:11.030355  5162 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:19:11.030555  5162 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:11.038759  5237 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.5.10.190:44043 every 8 connection(s)
I20260812 06:19:11.038770  5162 rpc_server.cc:307] RPC server started. Bound to: 127.5.10.190:44043
I20260812 06:19:11.041224  5238 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:11.046869  5238 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 3c520b60a6b1456fb9dc3669c8e7f4c7: Bootstrap starting.
I20260812 06:19:11.049233  5238 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 3c520b60a6b1456fb9dc3669c8e7f4c7: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:11.050246  5238 log.cc:826] T 00000000000000000000000000000000 P 3c520b60a6b1456fb9dc3669c8e7f4c7: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:11.052002  5238 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 3c520b60a6b1456fb9dc3669c8e7f4c7: No bootstrap required, opened a new log
I20260812 06:19:11.054801  5238 raft_consensus.cc:359] T 00000000000000000000000000000000 P 3c520b60a6b1456fb9dc3669c8e7f4c7 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3c520b60a6b1456fb9dc3669c8e7f4c7" member_type: VOTER }
I20260812 06:19:11.054968  5238 raft_consensus.cc:385] T 00000000000000000000000000000000 P 3c520b60a6b1456fb9dc3669c8e7f4c7 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:11.055011  5238 raft_consensus.cc:740] T 00000000000000000000000000000000 P 3c520b60a6b1456fb9dc3669c8e7f4c7 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 3c520b60a6b1456fb9dc3669c8e7f4c7, State: Initialized, Role: FOLLOWER
I20260812 06:19:11.055550  5238 consensus_queue.cc:260] T 00000000000000000000000000000000 P 3c520b60a6b1456fb9dc3669c8e7f4c7 [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: "3c520b60a6b1456fb9dc3669c8e7f4c7" member_type: VOTER }
I20260812 06:19:11.055683  5238 raft_consensus.cc:399] T 00000000000000000000000000000000 P 3c520b60a6b1456fb9dc3669c8e7f4c7 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:11.055732  5238 raft_consensus.cc:493] T 00000000000000000000000000000000 P 3c520b60a6b1456fb9dc3669c8e7f4c7 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:11.055819  5238 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 3c520b60a6b1456fb9dc3669c8e7f4c7 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:11.056584  5238 raft_consensus.cc:515] T 00000000000000000000000000000000 P 3c520b60a6b1456fb9dc3669c8e7f4c7 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3c520b60a6b1456fb9dc3669c8e7f4c7" member_type: VOTER }
I20260812 06:19:11.056974  5238 leader_election.cc:304] T 00000000000000000000000000000000 P 3c520b60a6b1456fb9dc3669c8e7f4c7 [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: 3c520b60a6b1456fb9dc3669c8e7f4c7; no voters: 
I20260812 06:19:11.057250  5238 leader_election.cc:290] T 00000000000000000000000000000000 P 3c520b60a6b1456fb9dc3669c8e7f4c7 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:11.057399  5241 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 3c520b60a6b1456fb9dc3669c8e7f4c7 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:11.057648  5241 raft_consensus.cc:697] T 00000000000000000000000000000000 P 3c520b60a6b1456fb9dc3669c8e7f4c7 [term 1 LEADER]: Becoming Leader. State: Replica: 3c520b60a6b1456fb9dc3669c8e7f4c7, State: Running, Role: LEADER
I20260812 06:19:11.058131  5241 consensus_queue.cc:237] T 00000000000000000000000000000000 P 3c520b60a6b1456fb9dc3669c8e7f4c7 [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: "3c520b60a6b1456fb9dc3669c8e7f4c7" member_type: VOTER }
I20260812 06:19:11.058380  5238 sys_catalog.cc:565] T 00000000000000000000000000000000 P 3c520b60a6b1456fb9dc3669c8e7f4c7 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:11.060065  5243 sys_catalog.cc:455] T 00000000000000000000000000000000 P 3c520b60a6b1456fb9dc3669c8e7f4c7 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 3c520b60a6b1456fb9dc3669c8e7f4c7. Latest consensus state: current_term: 1 leader_uuid: "3c520b60a6b1456fb9dc3669c8e7f4c7" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3c520b60a6b1456fb9dc3669c8e7f4c7" member_type: VOTER } }
I20260812 06:19:11.060119  5242 sys_catalog.cc:455] T 00000000000000000000000000000000 P 3c520b60a6b1456fb9dc3669c8e7f4c7 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "3c520b60a6b1456fb9dc3669c8e7f4c7" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3c520b60a6b1456fb9dc3669c8e7f4c7" member_type: VOTER } }
I20260812 06:19:11.060231  5242 sys_catalog.cc:458] T 00000000000000000000000000000000 P 3c520b60a6b1456fb9dc3669c8e7f4c7 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:11.060182  5243 sys_catalog.cc:458] T 00000000000000000000000000000000 P 3c520b60a6b1456fb9dc3669c8e7f4c7 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:11.060626  5252 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:11.060940  5162 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:11.062887  5252 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:11.067602  5252 catalog_manager.cc:1383] Generated new cluster ID: ad0c435f408541ac9673742d5e1bbb3f
I20260812 06:19:11.067677  5252 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:11.080071  5252 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:11.081285  5252 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:11.092955  5252 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 3c520b60a6b1456fb9dc3669c8e7f4c7: Generated new TSK 0
I20260812 06:19:11.093815  5252 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:11.126385  5162 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:11.129360  5265 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:11.129377  5269 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:11.129487  5162 server_base.cc:1061] running on GCE node
W20260812 06:19:11.129386  5266 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:11.129984  5162 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:11.130048  5162 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:11.130071  5162 hybrid_clock.cc:648] HybridClock initialized: now 1786515551130071 us; error 0 us; skew 500 ppm
I20260812 06:19:11.131060  5162 webserver.cc:533] Webserver started at http://127.5.10.129:43151/ using document root <none> and password file <none>
I20260812 06:19:11.131238  5162 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:11.131310  5162 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:11.131390  5162 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:11.131844  5162 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550972950-5162-0/minicluster-data/ts-0-root/instance:
uuid: "6a251879e2074727a370217c280b4218"
format_stamp: "Formatted at 2026-08-12 06:19:11 on dist-test-slave-0kls"
I20260812 06:19:11.133759  5162 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:11.134908  5275 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:11.135236  5162 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:11.135303  5162 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550972950-5162-0/minicluster-data/ts-0-root
uuid: "6a251879e2074727a370217c280b4218"
format_stamp: "Formatted at 2026-08-12 06:19:11 on dist-test-slave-0kls"
I20260812 06:19:11.135391  5162 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550972950-5162-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550972950-5162-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550972950-5162-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:11.146229  5162 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:11.146736  5162 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:11.147277  5162 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:11.148124  5162 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:11.148183  5162 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:11.148258  5162 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:11.148295  5162 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:11.155241  5162 rpc_server.cc:307] RPC server started. Bound to: 127.5.10.129:36533
I20260812 06:19:11.155277  5348 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.5.10.129:36533 every 8 connection(s)
I20260812 06:19:11.165427  5349 heartbeater.cc:344] Connected to a master server at 127.5.10.190:44043
I20260812 06:19:11.165705  5349 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:11.166239  5349 heartbeater.cc:507] Master 127.5.10.190:44043 requested a full tablet report, sending...
I20260812 06:19:11.167847  5197 ts_manager.cc:194] Registered new tserver with Master: 6a251879e2074727a370217c280b4218 (127.5.10.129:36533)
I20260812 06:19:11.168231  5162 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012326264s
I20260812 06:19:11.169394  5197 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:56438
I20260812 06:19:11.178706  5197 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:56446:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:11.194958  5305 tablet_service.cc:1511] Processing CreateTablet for tablet 84a0e7ba96614dca96848803dfc9a86d (DEFAULT_TABLE table=heavy-update-compaction-test [id=01990e2ab33542f59ac1c7bea77380fe]), partition=
I20260812 06:19:11.195488  5305 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 84a0e7ba96614dca96848803dfc9a86d. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:11.197883  5364 tablet_bootstrap.cc:492] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218: Bootstrap starting.
I20260812 06:19:11.199117  5364 tablet_bootstrap.cc:654] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:11.200575  5364 tablet_bootstrap.cc:492] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218: No bootstrap required, opened a new log
I20260812 06:19:11.200696  5364 ts_tablet_manager.cc:1403] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:19:11.201263  5364 raft_consensus.cc:359] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6a251879e2074727a370217c280b4218" member_type: VOTER last_known_addr { host: "127.5.10.129" port: 36533 } }
I20260812 06:19:11.201403  5364 raft_consensus.cc:385] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:11.201445  5364 raft_consensus.cc:740] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 6a251879e2074727a370217c280b4218, State: Initialized, Role: FOLLOWER
I20260812 06:19:11.201601  5364 consensus_queue.cc:260] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218 [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: "6a251879e2074727a370217c280b4218" member_type: VOTER last_known_addr { host: "127.5.10.129" port: 36533 } }
I20260812 06:19:11.201687  5364 raft_consensus.cc:399] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:11.201725  5364 raft_consensus.cc:493] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:11.201772  5364 raft_consensus.cc:3060] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:11.202872  5364 raft_consensus.cc:515] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6a251879e2074727a370217c280b4218" member_type: VOTER last_known_addr { host: "127.5.10.129" port: 36533 } }
I20260812 06:19:11.203035  5364 leader_election.cc:304] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218 [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: 6a251879e2074727a370217c280b4218; no voters: 
I20260812 06:19:11.203274  5364 leader_election.cc:290] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:11.203405  5366 raft_consensus.cc:2804] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:11.203622  5364 ts_tablet_manager.cc:1434] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218: Time spent starting tablet: real 0.003s	user 0.001s	sys 0.003s
I20260812 06:19:11.203670  5366 raft_consensus.cc:697] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218 [term 1 LEADER]: Becoming Leader. State: Replica: 6a251879e2074727a370217c280b4218, State: Running, Role: LEADER
I20260812 06:19:11.203871  5349 heartbeater.cc:499] Master 127.5.10.190:44043 was elected leader, sending a full tablet report...
I20260812 06:19:11.203855  5366 consensus_queue.cc:237] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218 [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: "6a251879e2074727a370217c280b4218" member_type: VOTER last_known_addr { host: "127.5.10.129" port: 36533 } }
I20260812 06:19:11.206609  5197 catalog_manager.cc:5719] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218 reported cstate change: term changed from 0 to 1, leader changed from <none> to 6a251879e2074727a370217c280b4218 (127.5.10.129). New cstate: current_term: 1 leader_uuid: "6a251879e2074727a370217c280b4218" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6a251879e2074727a370217c280b4218" member_type: VOTER last_known_addr { host: "127.5.10.129" port: 36533 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:11.281499  5162 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.065s	user 0.028s	sys 0.008s
I20260812 06:19:11.406342  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling FlushMRSOp(84a0e7ba96614dca96848803dfc9a86d): perf score=15.086190
I20260812 06:19:11.571811  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: FlushMRSOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.165s	user 0.135s	sys 0.028s Metrics: {"bytes_written":12635684,"cfile_init":1,"compiler_manager_pool.queue_time_us":192,"delete_count":0,"dirs.queue_time_us":100,"dirs.run_cpu_time_us":233,"dirs.run_wall_time_us":1003,"drs_written":1,"lbm_read_time_us":74,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40606,"lbm_writes_lt_1ms":675,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":348672,"thread_start_us":123,"threads_started":1,"update_count":1540}
I20260812 06:19:11.573061  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling LogGCOp(84a0e7ba96614dca96848803dfc9a86d): free 20743880 bytes of WAL
I20260812 06:19:11.573390  5280 log_reader.cc:385] T 84a0e7ba96614dca96848803dfc9a86d: removed 2 log segments from log reader
I20260812 06:19:11.573453  5280 log.cc:1079] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/84a0e7ba96614dca96848803dfc9a86d/wal-000000001 (ops 1-6)
I20260812 06:19:11.573506  5280 log.cc:1079] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/84a0e7ba96614dca96848803dfc9a86d/wal-000000002 (ops 7-11)
I20260812 06:19:11.578881  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: LogGCOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.006s	user 0.000s	sys 0.005s Metrics: {}
I20260812 06:19:11.579267  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling UndoDeltaBlockGCOp(84a0e7ba96614dca96848803dfc9a86d): 12719216 bytes on disk
I20260812 06:19:11.579977  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: UndoDeltaBlockGCOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4}
I20260812 06:19:11.580466  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d): perf score=4.173312
I20260812 06:19:11.599479  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.019s	user 0.004s	sys 0.013s Metrics: {"bytes_written":5866706,"delete_count":0,"lbm_write_time_us":7776,"lbm_writes_lt_1ms":146,"reinsert_count":0,"update_count":715}
I20260812 06:19:11.600049  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d): perf score=1.000000
I20260812 06:19:11.607115  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.007s	user 0.006s	sys 0.000s Metrics: {"bytes_written":1600127,"delete_count":0,"lbm_write_time_us":2132,"lbm_writes_lt_1ms":42,"reinsert_count":0,"update_count":195}
I20260812 06:19:11.607574  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling MajorDeltaCompactionOp(84a0e7ba96614dca96848803dfc9a86d): perf score=1.000000
I20260812 06:19:11.789001  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: MajorDeltaCompactionOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.181s	user 0.120s	sys 0.051s Metrics: {"cfile_cache_miss":523,"cfile_cache_miss_bytes":24364512,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":865,"lbm_read_time_us":11479,"lbm_reads_lt_1ms":559,"lbm_write_time_us":30151,"lbm_writes_lt_1ms":533,"peak_mem_usage":61665166,"reinsert_count":0,"spinlock_wait_cycles":1792,"thread_start_us":312,"threads_started":5,"update_count":2450}
I20260812 06:19:11.789520  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d): perf score=11.118625
I20260812 06:19:11.827621  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.038s	user 0.029s	sys 0.007s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15983,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:11.828212  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d): perf score=2.188937
I20260812 06:19:11.855383  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.027s	user 0.004s	sys 0.012s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6219,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:11.855837  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d): perf score=2.188937
I20260812 06:19:11.867219  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4197,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:11.867708  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling MajorDeltaCompactionOp(84a0e7ba96614dca96848803dfc9a86d): perf score=1.000000
I20260812 06:19:12.019685  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: MajorDeltaCompactionOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.152s	user 0.123s	sys 0.028s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1833,"lbm_read_time_us":11281,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30170,"lbm_writes_lt_1ms":543,"mutex_wait_us":643,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6400,"update_count":2500}
I20260812 06:19:12.020761  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d): perf score=10.126437
I20260812 06:19:12.053614  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.033s	user 0.022s	sys 0.007s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14306,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:12.054288  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d): perf score=2.188937
I20260812 06:19:12.073096  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.019s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6782,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:12.073601  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling MajorDeltaCompactionOp(84a0e7ba96614dca96848803dfc9a86d): perf score=1.000000
I20260812 06:19:12.202342  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: MajorDeltaCompactionOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.128s	user 0.095s	sys 0.033s 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":856,"lbm_read_time_us":7674,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25266,"lbm_writes_lt_1ms":443,"mutex_wait_us":1,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:19:12.203011  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d): perf score=11.118625
I20260812 06:19:12.240106  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.037s	user 0.011s	sys 0.021s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14930,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:12.240736  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d): perf score=2.188937
I20260812 06:19:12.255899  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5672,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:12.256450  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling MajorDeltaCompactionOp(84a0e7ba96614dca96848803dfc9a86d): perf score=1.000000
I20260812 06:19:12.382396  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: MajorDeltaCompactionOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.126s	user 0.094s	sys 0.031s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":264,"lbm_read_time_us":8486,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26343,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":26368,"update_count":2000}
I20260812 06:19:12.382995  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d): perf score=10.126437
I20260812 06:19:12.434746  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.052s	user 0.019s	sys 0.027s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17409,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:12.435292  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d): perf score=2.188937
I20260812 06:19:12.446267  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4256,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:12.446782  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling MajorDeltaCompactionOp(84a0e7ba96614dca96848803dfc9a86d): perf score=1.000000
I20260812 06:19:12.598188  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: MajorDeltaCompactionOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.151s	user 0.111s	sys 0.040s 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":328,"lbm_read_time_us":11093,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24187,"lbm_writes_lt_1ms":443,"mutex_wait_us":41,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11392,"update_count":2000}
I20260812 06:19:12.599015  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d): perf score=10.126437
I20260812 06:19:12.648643  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.049s	user 0.029s	sys 0.004s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15937,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:12.649227  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d): perf score=2.188937
I20260812 06:19:12.660652  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3999,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:12.661216  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling MajorDeltaCompactionOp(84a0e7ba96614dca96848803dfc9a86d): perf score=1.000000
I20260812 06:19:12.793865  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: MajorDeltaCompactionOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.132s	user 0.105s	sys 0.027s 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":222,"lbm_read_time_us":10493,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25263,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2000}
I20260812 06:19:12.794626  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d): perf score=10.126437
I20260812 06:19:12.831506  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.037s	user 0.015s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16421,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:12.832060  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d): perf score=2.188937
I20260812 06:19:12.856590  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.024s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5007,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:12.857087  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d): perf score=2.188937
I20260812 06:19:12.868232  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4211,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:12.868767  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling FlushMRSOp(84a0e7ba96614dca96848803dfc9a86d): perf score=1.000000
I20260812 06:19:12.899840  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: FlushMRSOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.031s	user 0.025s	sys 0.004s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":119,"dirs.run_cpu_time_us":245,"dirs.run_wall_time_us":1366,"drs_written":1,"lbm_read_time_us":76,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1727,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:12.900775  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling LogGCOp(84a0e7ba96614dca96848803dfc9a86d): free 124257269 bytes of WAL
I20260812 06:19:12.901075  5280 log_reader.cc:385] T 84a0e7ba96614dca96848803dfc9a86d: removed 12 log segments from log reader
I20260812 06:19:12.901146  5280 log.cc:1079] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/84a0e7ba96614dca96848803dfc9a86d/wal-000000003 (ops 12-16)
I20260812 06:19:12.901187  5280 log.cc:1079] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/84a0e7ba96614dca96848803dfc9a86d/wal-000000004 (ops 17-21)
I20260812 06:19:12.901216  5280 log.cc:1079] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/84a0e7ba96614dca96848803dfc9a86d/wal-000000005 (ops 22-26)
I20260812 06:19:12.901243  5280 log.cc:1079] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/84a0e7ba96614dca96848803dfc9a86d/wal-000000006 (ops 27-30)
I20260812 06:19:12.901268  5280 log.cc:1079] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/84a0e7ba96614dca96848803dfc9a86d/wal-000000007 (ops 31-35)
I20260812 06:19:12.901294  5280 log.cc:1079] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/84a0e7ba96614dca96848803dfc9a86d/wal-000000008 (ops 36-40)
I20260812 06:19:12.901327  5280 log.cc:1079] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/84a0e7ba96614dca96848803dfc9a86d/wal-000000009 (ops 41-45)
I20260812 06:19:12.901350  5280 log.cc:1079] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/84a0e7ba96614dca96848803dfc9a86d/wal-000000010 (ops 46-50)
I20260812 06:19:12.901372  5280 log.cc:1079] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/84a0e7ba96614dca96848803dfc9a86d/wal-000000011 (ops 51-55)
I20260812 06:19:12.901400  5280 log.cc:1079] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/84a0e7ba96614dca96848803dfc9a86d/wal-000000012 (ops 56-60)
I20260812 06:19:12.901424  5280 log.cc:1079] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/84a0e7ba96614dca96848803dfc9a86d/wal-000000013 (ops 61-65)
I20260812 06:19:12.901458  5280 log.cc:1079] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/84a0e7ba96614dca96848803dfc9a86d/wal-000000014 (ops 66-70)
I20260812 06:19:12.932279  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: LogGCOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.031s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:19:12.932796  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d): perf score=2.188937
I20260812 06:19:12.956300  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.023s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5634,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:12.956866  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling UndoDeltaBlockGCOp(84a0e7ba96614dca96848803dfc9a86d): 472 bytes on disk
I20260812 06:19:12.957412  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: UndoDeltaBlockGCOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4}
I20260812 06:19:12.957979  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d): perf score=2.188937
I20260812 06:19:12.969385  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.011s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4196,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:12.970029  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling MajorDeltaCompactionOp(84a0e7ba96614dca96848803dfc9a86d): perf score=1.000000
I20260812 06:19:13.161294  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: MajorDeltaCompactionOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.191s	user 0.158s	sys 0.033s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979867,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":668,"lbm_read_time_us":12814,"lbm_reads_lt_1ms":775,"lbm_write_time_us":39062,"lbm_writes_lt_1ms":743,"mutex_wait_us":359,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":40192,"thread_start_us":85,"threads_started":1,"update_count":3500}
I20260812 06:19:13.162129  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d): perf score=14.095187
I20260812 06:19:13.211755  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.049s	user 0.022s	sys 0.026s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22054,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:13.212318  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d): perf score=2.188937
I20260812 06:19:13.237838  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.025s	user 0.006s	sys 0.014s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6170,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:13.238588  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling MajorDeltaCompactionOp(84a0e7ba96614dca96848803dfc9a86d): perf score=1.000000
I20260812 06:19:13.403786  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: MajorDeltaCompactionOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.165s	user 0.100s	sys 0.065s 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":198,"lbm_read_time_us":12053,"lbm_reads_lt_1ms":564,"lbm_write_time_us":27935,"lbm_writes_lt_1ms":543,"mutex_wait_us":50,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11264,"update_count":2500}
I20260812 06:19:13.404412  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d): perf score=14.095187
I20260812 06:19:13.457664  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.053s	user 0.025s	sys 0.024s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23416,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:13.458238  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d): perf score=2.188937
I20260812 06:19:13.469897  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.011s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4064,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:13.470443  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling MajorDeltaCompactionOp(84a0e7ba96614dca96848803dfc9a86d): perf score=1.000000
I20260812 06:19:13.621500  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: MajorDeltaCompactionOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.151s	user 0.130s	sys 0.020s 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":377,"lbm_read_time_us":10486,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32324,"lbm_writes_lt_1ms":543,"mutex_wait_us":270,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":2500}
I20260812 06:19:13.624455  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d): perf score=11.118625
I20260812 06:19:13.666700  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.041s	user 0.026s	sys 0.014s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17531,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:13.667472  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d): perf score=2.188937
I20260812 06:19:13.685364  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.018s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4636,"lbm_writes_lt_1ms":93,"reinsert_count":0,"spinlock_wait_cycles":5376,"update_count":450}
I20260812 06:19:13.686177  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling MajorDeltaCompactionOp(84a0e7ba96614dca96848803dfc9a86d): perf score=1.000000
I20260812 06:19:13.830958  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: MajorDeltaCompactionOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.145s	user 0.111s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":232,"lbm_read_time_us":7742,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27637,"lbm_writes_lt_1ms":443,"mutex_wait_us":46,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5504,"update_count":2000}
I20260812 06:19:13.831735  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d): perf score=14.095187
I20260812 06:19:13.880075  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.048s	user 0.035s	sys 0.008s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20018,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:13.880563  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d): perf score=2.188937
I20260812 06:19:13.892663  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4269,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:13.893421  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling MajorDeltaCompactionOp(84a0e7ba96614dca96848803dfc9a86d): perf score=1.000000
I20260812 06:19:14.068161  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: MajorDeltaCompactionOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.174s	user 0.138s	sys 0.027s 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":1442,"lbm_read_time_us":11661,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30651,"lbm_writes_lt_1ms":543,"mutex_wait_us":555,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":18048,"update_count":2500}
I20260812 06:19:14.068866  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d): perf score=14.095187
I20260812 06:19:14.114022  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.045s	user 0.029s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20417,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:14.114501  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling MajorDeltaCompactionOp(84a0e7ba96614dca96848803dfc9a86d): perf score=1.000000
I20260812 06:19:14.269940  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: MajorDeltaCompactionOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.155s	user 0.102s	sys 0.047s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":178,"lbm_read_time_us":9850,"lbm_reads_lt_1ms":463,"lbm_write_time_us":26834,"lbm_writes_lt_1ms":443,"mutex_wait_us":368,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2000}
I20260812 06:19:14.270800  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d): perf score=11.118625
I20260812 06:19:14.312625  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.041s	user 0.024s	sys 0.014s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":17930,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:14.313202  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d): perf score=2.188937
I20260812 06:19:14.342129  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.029s	user 0.007s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5829,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:14.342581  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d): perf score=2.188937
I20260812 06:19:14.352944  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3978,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:14.353410  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling FlushMRSOp(84a0e7ba96614dca96848803dfc9a86d): perf score=1.000000
I20260812 06:19:14.392472  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: FlushMRSOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.039s	user 0.036s	sys 0.000s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":73,"dirs.run_cpu_time_us":181,"dirs.run_wall_time_us":1505,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1669,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:14.393280  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling LogGCOp(84a0e7ba96614dca96848803dfc9a86d): free 120553382 bytes of WAL
I20260812 06:19:14.393564  5280 log_reader.cc:385] T 84a0e7ba96614dca96848803dfc9a86d: removed 12 log segments from log reader
I20260812 06:19:14.393623  5280 log.cc:1079] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/84a0e7ba96614dca96848803dfc9a86d/wal-000000015 (ops 71-75)
I20260812 06:19:14.393662  5280 log.cc:1079] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/84a0e7ba96614dca96848803dfc9a86d/wal-000000016 (ops 76-80)
I20260812 06:19:14.393695  5280 log.cc:1079] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/84a0e7ba96614dca96848803dfc9a86d/wal-000000017 (ops 81-85)
I20260812 06:19:14.393730  5280 log.cc:1079] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/84a0e7ba96614dca96848803dfc9a86d/wal-000000018 (ops 86-90)
I20260812 06:19:14.393755  5280 log.cc:1079] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/84a0e7ba96614dca96848803dfc9a86d/wal-000000019 (ops 91-95)
I20260812 06:19:14.393808  5280 log.cc:1079] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/84a0e7ba96614dca96848803dfc9a86d/wal-000000020 (ops 96-100)
I20260812 06:19:14.393841  5280 log.cc:1079] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/84a0e7ba96614dca96848803dfc9a86d/wal-000000021 (ops 101-104)
I20260812 06:19:14.393863  5280 log.cc:1079] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/84a0e7ba96614dca96848803dfc9a86d/wal-000000022 (ops 105-109)
I20260812 06:19:14.393890  5280 log.cc:1079] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/84a0e7ba96614dca96848803dfc9a86d/wal-000000023 (ops 110-114)
I20260812 06:19:14.393920  5280 log.cc:1079] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/84a0e7ba96614dca96848803dfc9a86d/wal-000000024 (ops 115-118)
I20260812 06:19:14.393952  5280 log.cc:1079] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/84a0e7ba96614dca96848803dfc9a86d/wal-000000025 (ops 119-123)
I20260812 06:19:14.393980  5280 log.cc:1079] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/84a0e7ba96614dca96848803dfc9a86d/wal-000000026 (ops 124-128)
I20260812 06:19:14.425633  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: LogGCOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.032s	user 0.001s	sys 0.027s Metrics: {}
I20260812 06:19:14.426070  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling UndoDeltaBlockGCOp(84a0e7ba96614dca96848803dfc9a86d): 473 bytes on disk
I20260812 06:19:14.426561  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: UndoDeltaBlockGCOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4}
I20260812 06:19:14.427095  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d): perf score=2.188937
I20260812 06:19:14.451854  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.025s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5988,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:14.452450  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d): perf score=2.188937
I20260812 06:19:14.463385  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4090,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:14.463896  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling MajorDeltaCompactionOp(84a0e7ba96614dca96848803dfc9a86d): perf score=1.000000
I20260812 06:19:14.711514  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: MajorDeltaCompactionOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.247s	user 0.162s	sys 0.079s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979861,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":404,"lbm_read_time_us":16415,"lbm_reads_lt_1ms":775,"lbm_write_time_us":41402,"lbm_writes_lt_1ms":743,"mutex_wait_us":47,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":32000,"thread_start_us":86,"threads_started":1,"update_count":3500}
I20260812 06:19:14.712301  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d): perf score=18.063937
I20260812 06:19:14.777036  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.065s	user 0.028s	sys 0.032s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":27133,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:14.777560  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d): perf score=2.188937
I20260812 06:19:14.790355  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.013s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4363,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:14.793269  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling MajorDeltaCompactionOp(84a0e7ba96614dca96848803dfc9a86d): perf score=1.000000
I20260812 06:19:15.011870  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: MajorDeltaCompactionOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.218s	user 0.149s	sys 0.063s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877103,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":909,"lbm_read_time_us":13791,"lbm_reads_lt_1ms":664,"lbm_write_time_us":35550,"lbm_writes_lt_1ms":643,"mutex_wait_us":370,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":36992,"update_count":3000}
I20260812 06:19:15.012574  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d): perf score=18.063937
I20260812 06:19:15.089186  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.076s	user 0.049s	sys 0.012s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":28732,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:15.089854  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d): perf score=2.188937
I20260812 06:19:15.100422  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3850,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:15.101269  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling MajorDeltaCompactionOp(84a0e7ba96614dca96848803dfc9a86d): perf score=1.000000
I20260812 06:19:15.287693  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: MajorDeltaCompactionOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.186s	user 0.125s	sys 0.059s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":361,"lbm_read_time_us":12185,"lbm_reads_lt_1ms":672,"lbm_write_time_us":33233,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3712,"update_count":3000}
I20260812 06:19:15.288292  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d): perf score=15.087375
I20260812 06:19:15.340833  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.052s	user 0.030s	sys 0.020s Metrics: {"bytes_written":16820138,"delete_count":0,"lbm_write_time_us":22716,"lbm_writes_lt_1ms":413,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2050}
I20260812 06:19:15.341617  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d): perf score=2.188937
I20260812 06:19:15.355476  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.014s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3905,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:15.356093  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling MajorDeltaCompactionOp(84a0e7ba96614dca96848803dfc9a86d): perf score=1.000000
I20260812 06:19:15.516458  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: MajorDeltaCompactionOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.160s	user 0.114s	sys 0.045s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774671,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":785,"lbm_read_time_us":11962,"lbm_reads_lt_1ms":564,"lbm_write_time_us":26976,"lbm_writes_lt_1ms":543,"mutex_wait_us":348,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:15.517143  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d): perf score=14.095187
I20260812 06:19:15.575651  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.058s	user 0.037s	sys 0.019s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21661,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2000}
I20260812 06:19:15.576208  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d): perf score=2.188937
I20260812 06:19:15.592535  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.016s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4561,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:15.593171  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling MajorDeltaCompactionOp(84a0e7ba96614dca96848803dfc9a86d): perf score=1.000000
I20260812 06:19:15.763299  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: MajorDeltaCompactionOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.170s	user 0.114s	sys 0.055s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":928,"lbm_read_time_us":11198,"lbm_reads_lt_1ms":564,"lbm_write_time_us":28629,"lbm_writes_lt_1ms":543,"mutex_wait_us":308,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2500}
I20260812 06:19:15.763929  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d): perf score=14.095187
I20260812 06:19:15.821149  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.057s	user 0.030s	sys 0.023s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21632,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:15.821903  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d): perf score=3.181125
I20260812 06:19:15.836027  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.014s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4481,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:15.836576  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d): perf score=2.188937
I20260812 06:19:15.846359  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3648,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:15.846809  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling FlushMRSOp(84a0e7ba96614dca96848803dfc9a86d): perf score=1.000000
I20260812 06:19:15.879240  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: FlushMRSOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.032s	user 0.027s	sys 0.004s Metrics: {"bytes_written":1234477,"cfile_init":1,"dirs.queue_time_us":81,"dirs.run_cpu_time_us":239,"dirs.run_wall_time_us":1594,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1498,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:15.880105  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling LogGCOp(84a0e7ba96614dca96848803dfc9a86d): free 129320774 bytes of WAL
I20260812 06:19:15.880402  5280 log_reader.cc:385] T 84a0e7ba96614dca96848803dfc9a86d: removed 13 log segments from log reader
I20260812 06:19:15.880481  5280 log.cc:1079] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/84a0e7ba96614dca96848803dfc9a86d/wal-000000027 (ops 129-133)
I20260812 06:19:15.880534  5280 log.cc:1079] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/84a0e7ba96614dca96848803dfc9a86d/wal-000000028 (ops 134-138)
I20260812 06:19:15.880594  5280 log.cc:1079] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/84a0e7ba96614dca96848803dfc9a86d/wal-000000029 (ops 139-143)
I20260812 06:19:15.880633  5280 log.cc:1079] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/84a0e7ba96614dca96848803dfc9a86d/wal-000000030 (ops 144-148)
I20260812 06:19:15.880678  5280 log.cc:1079] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/84a0e7ba96614dca96848803dfc9a86d/wal-000000031 (ops 149-152)
I20260812 06:19:15.880715  5280 log.cc:1079] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/84a0e7ba96614dca96848803dfc9a86d/wal-000000032 (ops 153-157)
I20260812 06:19:15.880752  5280 log.cc:1079] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/84a0e7ba96614dca96848803dfc9a86d/wal-000000033 (ops 158-162)
I20260812 06:19:15.880789  5280 log.cc:1079] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/84a0e7ba96614dca96848803dfc9a86d/wal-000000034 (ops 163-167)
I20260812 06:19:15.880825  5280 log.cc:1079] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/84a0e7ba96614dca96848803dfc9a86d/wal-000000035 (ops 168-172)
I20260812 06:19:15.880861  5280 log.cc:1079] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/84a0e7ba96614dca96848803dfc9a86d/wal-000000036 (ops 173-176)
I20260812 06:19:15.880897  5280 log.cc:1079] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/84a0e7ba96614dca96848803dfc9a86d/wal-000000037 (ops 177-181)
I20260812 06:19:15.880934  5280 log.cc:1079] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/84a0e7ba96614dca96848803dfc9a86d/wal-000000038 (ops 182-186)
I20260812 06:19:15.880970  5280 log.cc:1079] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/84a0e7ba96614dca96848803dfc9a86d/wal-000000039 (ops 187-191)
I20260812 06:19:15.910560  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: LogGCOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.030s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:19:15.911327  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling UndoDeltaBlockGCOp(84a0e7ba96614dca96848803dfc9a86d): 471 bytes on disk
I20260812 06:19:15.911834  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: UndoDeltaBlockGCOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4}
I20260812 06:19:15.913121  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d): perf score=5.165500
I20260812 06:19:15.930171  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.017s	user 0.013s	sys 0.004s Metrics: {"bytes_written":6317966,"delete_count":0,"lbm_write_time_us":7052,"lbm_writes_lt_1ms":157,"reinsert_count":0,"update_count":770}
I20260812 06:19:15.930675  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d): perf score=1.000000
I20260812 06:19:15.948235  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.017s	user 0.009s	sys 0.000s Metrics: {"bytes_written":1887302,"delete_count":0,"lbm_write_time_us":3271,"lbm_writes_lt_1ms":49,"reinsert_count":0,"update_count":230}
I20260812 06:19:15.948745  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling MajorDeltaCompactionOp(84a0e7ba96614dca96848803dfc9a86d): perf score=1.000000
I20260812 06:19:16.127326  5162 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.846s	user 1.758s	sys 0.161s
I20260812 06:19:16.206087  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: MajorDeltaCompactionOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.257s	user 0.181s	sys 0.076s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37082215,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"lbm_read_time_us":17455,"lbm_reads_lt_1ms":863,"lbm_write_time_us":48908,"lbm_writes_lt_1ms":843,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":4096,"update_count":4000}
I20260812 06:19:16.206583  5350 maintenance_manager.cc:419] P 6a251879e2074727a370217c280b4218: Scheduling FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d): perf score=14.095187
I20260812 06:19:16.237329  5162 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.109s	user 0.004s	sys 0.000s
I20260812 06:19:16.238353  5162 tablet_server.cc:179] TabletServer@127.5.10.129:0 shutting down...
I20260812 06:19:16.268973  5280 maintenance_manager.cc:643] P 6a251879e2074727a370217c280b4218: FlushDeltaMemStoresOp(84a0e7ba96614dca96848803dfc9a86d) complete. Timing: real 0.062s	user 0.029s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23926,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:16.269771  5162 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:16.270232  5162 tablet_replica.cc:333] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218: stopping tablet replica
I20260812 06:19:16.270474  5162 raft_consensus.cc:2243] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:16.270727  5162 raft_consensus.cc:2272] T 84a0e7ba96614dca96848803dfc9a86d P 6a251879e2074727a370217c280b4218 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:16.285461  5162 tablet_server.cc:196] TabletServer@127.5.10.129:0 shutdown complete.
I20260812 06:19:16.290297  5162 master.cc:562] Master@127.5.10.190:44043 shutting down...
I20260812 06:19:16.294759  5162 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 3c520b60a6b1456fb9dc3669c8e7f4c7 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:16.294970  5162 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 3c520b60a6b1456fb9dc3669c8e7f4c7 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:16.295063  5162 tablet_replica.cc:333] T 00000000000000000000000000000000 P 3c520b60a6b1456fb9dc3669c8e7f4c7: stopping tablet replica
I20260812 06:19:16.307475  5162 master.cc:584] Master@127.5.10.190:44043 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5418 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:16.402860  5162 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.5.10.190:34801
I20260812 06:19:16.403234  5162 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:16.405360  5385 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:16.405512  5387 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:16.405572  5162 server_base.cc:1061] running on GCE node
W20260812 06:19:16.405695  5389 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:16.405939  5162 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:16.406062  5162 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:16.406080  5162 hybrid_clock.cc:648] HybridClock initialized: now 1786515556406080 us; error 0 us; skew 500 ppm
I20260812 06:19:16.406934  5162 webserver.cc:533] Webserver started at http://127.5.10.190:42611/ using document root <none> and password file <none>
I20260812 06:19:16.407116  5162 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:16.407230  5162 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:16.407336  5162 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:16.407778  5162 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550972950-5162-0/minicluster-data/master-0-root/instance:
uuid: "eeb0899c514745fd9c7b9ebe901d57e2"
format_stamp: "Formatted at 2026-08-12 06:19:16 on dist-test-slave-0kls"
I20260812 06:19:16.409333  5162 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:16.410367  5394 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:16.410682  5162 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.000s
I20260812 06:19:16.410758  5162 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550972950-5162-0/minicluster-data/master-0-root
uuid: "eeb0899c514745fd9c7b9ebe901d57e2"
format_stamp: "Formatted at 2026-08-12 06:19:16 on dist-test-slave-0kls"
I20260812 06:19:16.410820  5162 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550972950-5162-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550972950-5162-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550972950-5162-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:16.417680  5162 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:16.418143  5162 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:16.422310  5162 rpc_server.cc:307] RPC server started. Bound to: 127.5.10.190:34801
I20260812 06:19:16.425047  5451 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.5.10.190:34801 every 8 connection(s)
I20260812 06:19:16.425567  5453 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:16.443291  5453 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P eeb0899c514745fd9c7b9ebe901d57e2: Bootstrap starting.
I20260812 06:19:16.444355  5453 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P eeb0899c514745fd9c7b9ebe901d57e2: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:16.445767  5453 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P eeb0899c514745fd9c7b9ebe901d57e2: No bootstrap required, opened a new log
I20260812 06:19:16.446326  5453 raft_consensus.cc:359] T 00000000000000000000000000000000 P eeb0899c514745fd9c7b9ebe901d57e2 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "eeb0899c514745fd9c7b9ebe901d57e2" member_type: VOTER }
I20260812 06:19:16.446451  5453 raft_consensus.cc:385] T 00000000000000000000000000000000 P eeb0899c514745fd9c7b9ebe901d57e2 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:16.446504  5453 raft_consensus.cc:740] T 00000000000000000000000000000000 P eeb0899c514745fd9c7b9ebe901d57e2 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: eeb0899c514745fd9c7b9ebe901d57e2, State: Initialized, Role: FOLLOWER
I20260812 06:19:16.446676  5453 consensus_queue.cc:260] T 00000000000000000000000000000000 P eeb0899c514745fd9c7b9ebe901d57e2 [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: "eeb0899c514745fd9c7b9ebe901d57e2" member_type: VOTER }
I20260812 06:19:16.446780  5453 raft_consensus.cc:399] T 00000000000000000000000000000000 P eeb0899c514745fd9c7b9ebe901d57e2 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:16.446826  5453 raft_consensus.cc:493] T 00000000000000000000000000000000 P eeb0899c514745fd9c7b9ebe901d57e2 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:16.446884  5453 raft_consensus.cc:3060] T 00000000000000000000000000000000 P eeb0899c514745fd9c7b9ebe901d57e2 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:16.447718  5453 raft_consensus.cc:515] T 00000000000000000000000000000000 P eeb0899c514745fd9c7b9ebe901d57e2 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "eeb0899c514745fd9c7b9ebe901d57e2" member_type: VOTER }
I20260812 06:19:16.447932  5453 leader_election.cc:304] T 00000000000000000000000000000000 P eeb0899c514745fd9c7b9ebe901d57e2 [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: eeb0899c514745fd9c7b9ebe901d57e2; no voters: 
I20260812 06:19:16.448237  5453 leader_election.cc:290] T 00000000000000000000000000000000 P eeb0899c514745fd9c7b9ebe901d57e2 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:16.448460  5456 raft_consensus.cc:2804] T 00000000000000000000000000000000 P eeb0899c514745fd9c7b9ebe901d57e2 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:16.448769  5456 raft_consensus.cc:697] T 00000000000000000000000000000000 P eeb0899c514745fd9c7b9ebe901d57e2 [term 1 LEADER]: Becoming Leader. State: Replica: eeb0899c514745fd9c7b9ebe901d57e2, State: Running, Role: LEADER
I20260812 06:19:16.448832  5453 sys_catalog.cc:565] T 00000000000000000000000000000000 P eeb0899c514745fd9c7b9ebe901d57e2 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:16.448949  5456 consensus_queue.cc:237] T 00000000000000000000000000000000 P eeb0899c514745fd9c7b9ebe901d57e2 [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: "eeb0899c514745fd9c7b9ebe901d57e2" member_type: VOTER }
I20260812 06:19:16.449466  5458 sys_catalog.cc:455] T 00000000000000000000000000000000 P eeb0899c514745fd9c7b9ebe901d57e2 [sys.catalog]: SysCatalogTable state changed. Reason: New leader eeb0899c514745fd9c7b9ebe901d57e2. Latest consensus state: current_term: 1 leader_uuid: "eeb0899c514745fd9c7b9ebe901d57e2" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "eeb0899c514745fd9c7b9ebe901d57e2" member_type: VOTER } }
I20260812 06:19:16.449587  5458 sys_catalog.cc:458] T 00000000000000000000000000000000 P eeb0899c514745fd9c7b9ebe901d57e2 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:16.449846  5457 sys_catalog.cc:455] T 00000000000000000000000000000000 P eeb0899c514745fd9c7b9ebe901d57e2 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "eeb0899c514745fd9c7b9ebe901d57e2" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "eeb0899c514745fd9c7b9ebe901d57e2" member_type: VOTER } }
I20260812 06:19:16.449962  5461 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:16.449962  5457 sys_catalog.cc:458] T 00000000000000000000000000000000 P eeb0899c514745fd9c7b9ebe901d57e2 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:16.451028  5461 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:16.451193  5162 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:16.453039  5461 catalog_manager.cc:1383] Generated new cluster ID: acd13dabcd974086afbc63463dfde461
I20260812 06:19:16.453088  5461 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:16.469456  5461 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:16.470180  5461 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:16.481014  5461 catalog_manager.cc:6092] T 00000000000000000000000000000000 P eeb0899c514745fd9c7b9ebe901d57e2: Generated new TSK 0
I20260812 06:19:16.481262  5461 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:16.483510  5162 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:16.485657  5480 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:16.485772  5162 server_base.cc:1061] running on GCE node
W20260812 06:19:16.485889  5478 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:16.485754  5477 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:16.486155  5162 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:16.486207  5162 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:16.486222  5162 hybrid_clock.cc:648] HybridClock initialized: now 1786515556486222 us; error 0 us; skew 500 ppm
I20260812 06:19:16.487116  5162 webserver.cc:533] Webserver started at http://127.5.10.129:36845/ using document root <none> and password file <none>
I20260812 06:19:16.487298  5162 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:16.487371  5162 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:16.487463  5162 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:16.487893  5162 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550972950-5162-0/minicluster-data/ts-0-root/instance:
uuid: "c0766134a9a143f3aee36349e36dde0c"
format_stamp: "Formatted at 2026-08-12 06:19:16 on dist-test-slave-0kls"
I20260812 06:19:16.489439  5162 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:16.490487  5486 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:16.490749  5162 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:16.490846  5162 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550972950-5162-0/minicluster-data/ts-0-root
uuid: "c0766134a9a143f3aee36349e36dde0c"
format_stamp: "Formatted at 2026-08-12 06:19:16 on dist-test-slave-0kls"
I20260812 06:19:16.490934  5162 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550972950-5162-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550972950-5162-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550972950-5162-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:16.502163  5162 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:16.502580  5162 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:16.502904  5162 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:16.503393  5162 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:16.503454  5162 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:16.503517  5162 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:16.503563  5162 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:16.508111  5162 rpc_server.cc:307] RPC server started. Bound to: 127.5.10.129:38255
I20260812 06:19:16.508139  5560 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.5.10.129:38255 every 8 connection(s)
I20260812 06:19:16.521011  5561 heartbeater.cc:344] Connected to a master server at 127.5.10.190:34801
I20260812 06:19:16.521203  5561 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:16.521492  5561 heartbeater.cc:507] Master 127.5.10.190:34801 requested a full tablet report, sending...
I20260812 06:19:16.522241  5413 ts_manager.cc:194] Registered new tserver with Master: c0766134a9a143f3aee36349e36dde0c (127.5.10.129:38255)
I20260812 06:19:16.523046  5413 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:38474
I20260812 06:19:16.523169  5162 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.01462672s
I20260812 06:19:16.530495  5413 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:38484:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:16.539330  5518 tablet_service.cc:1511] Processing CreateTablet for tablet 4222e42b4cd64d61a9e751959bc02c2d (DEFAULT_TABLE table=heavy-update-compaction-test [id=caa7f6ff0616449cb0d92d0bca648845]), partition=
I20260812 06:19:16.539656  5518 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 4222e42b4cd64d61a9e751959bc02c2d. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:16.541875  5573 tablet_bootstrap.cc:492] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c: Bootstrap starting.
I20260812 06:19:16.542774  5573 tablet_bootstrap.cc:654] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:16.543928  5573 tablet_bootstrap.cc:492] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c: No bootstrap required, opened a new log
I20260812 06:19:16.544054  5573 ts_tablet_manager.cc:1403] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:16.544587  5573 raft_consensus.cc:359] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c0766134a9a143f3aee36349e36dde0c" member_type: VOTER last_known_addr { host: "127.5.10.129" port: 38255 } }
I20260812 06:19:16.544718  5573 raft_consensus.cc:385] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:16.544799  5573 raft_consensus.cc:740] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: c0766134a9a143f3aee36349e36dde0c, State: Initialized, Role: FOLLOWER
I20260812 06:19:16.544987  5573 consensus_queue.cc:260] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c [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: "c0766134a9a143f3aee36349e36dde0c" member_type: VOTER last_known_addr { host: "127.5.10.129" port: 38255 } }
I20260812 06:19:16.545120  5573 raft_consensus.cc:399] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:16.545161  5573 raft_consensus.cc:493] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:16.545217  5573 raft_consensus.cc:3060] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:16.546025  5573 raft_consensus.cc:515] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c0766134a9a143f3aee36349e36dde0c" member_type: VOTER last_known_addr { host: "127.5.10.129" port: 38255 } }
I20260812 06:19:16.546150  5573 leader_election.cc:304] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c [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: c0766134a9a143f3aee36349e36dde0c; no voters: 
I20260812 06:19:16.546300  5573 leader_election.cc:290] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:16.546447  5575 raft_consensus.cc:2804] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:16.546645  5573 ts_tablet_manager.cc:1434] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:19:16.546684  5575 raft_consensus.cc:697] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c [term 1 LEADER]: Becoming Leader. State: Replica: c0766134a9a143f3aee36349e36dde0c, State: Running, Role: LEADER
I20260812 06:19:16.546684  5561 heartbeater.cc:499] Master 127.5.10.190:34801 was elected leader, sending a full tablet report...
I20260812 06:19:16.546931  5575 consensus_queue.cc:237] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c [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: "c0766134a9a143f3aee36349e36dde0c" member_type: VOTER last_known_addr { host: "127.5.10.129" port: 38255 } }
I20260812 06:19:16.548301  5413 catalog_manager.cc:5719] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c reported cstate change: term changed from 0 to 1, leader changed from <none> to c0766134a9a143f3aee36349e36dde0c (127.5.10.129). New cstate: current_term: 1 leader_uuid: "c0766134a9a143f3aee36349e36dde0c" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c0766134a9a143f3aee36349e36dde0c" member_type: VOTER last_known_addr { host: "127.5.10.129" port: 38255 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:16.608434  5162 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.053s	user 0.019s	sys 0.004s
I20260812 06:19:16.759028  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling FlushMRSOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=19.054940
I20260812 06:19:16.916821  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: FlushMRSOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.157s	user 0.127s	sys 0.028s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":73,"dirs.run_cpu_time_us":206,"dirs.run_wall_time_us":784,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":42709,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:19:16.917485  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling LogGCOp(4222e42b4cd64d61a9e751959bc02c2d): free 20743880 bytes of WAL
I20260812 06:19:16.917744  5492 log_reader.cc:385] T 4222e42b4cd64d61a9e751959bc02c2d: removed 2 log segments from log reader
I20260812 06:19:16.917841  5492 log.cc:1079] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/4222e42b4cd64d61a9e751959bc02c2d/wal-000000001 (ops 1-6)
I20260812 06:19:16.917900  5492 log.cc:1079] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/4222e42b4cd64d61a9e751959bc02c2d/wal-000000002 (ops 7-11)
I20260812 06:19:16.922063  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: LogGCOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.004s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:19:16.922448  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=2.188937
I20260812 06:19:16.939514  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.017s	user 0.009s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5341,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:16.940009  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling UndoDeltaBlockGCOp(4222e42b4cd64d61a9e751959bc02c2d): 16411393 bytes on disk
I20260812 06:19:16.940511  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: UndoDeltaBlockGCOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:19:16.940919  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling MajorDeltaCompactionOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=1.000000
I20260812 06:19:17.086619  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: MajorDeltaCompactionOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.146s	user 0.102s	sys 0.040s 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":578,"lbm_read_time_us":10836,"lbm_reads_lt_1ms":460,"lbm_write_time_us":25663,"lbm_writes_lt_1ms":443,"mutex_wait_us":116,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1408,"thread_start_us":341,"threads_started":5,"update_count":2000}
I20260812 06:19:17.087247  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=11.118625
I20260812 06:19:17.120754  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.033s	user 0.022s	sys 0.008s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13615,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:17.121224  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=2.188937
I20260812 06:19:17.134073  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.013s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4551,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:17.134691  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling MajorDeltaCompactionOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=1.000000
I20260812 06:19:17.266901  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: MajorDeltaCompactionOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.132s	user 0.102s	sys 0.030s 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":413,"lbm_read_time_us":9243,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26217,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:19:17.267587  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=10.126437
I20260812 06:19:17.316982  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.049s	user 0.028s	sys 0.009s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":18626,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:17.317535  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=2.188937
I20260812 06:19:17.329663  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.012s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4308,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:17.330318  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling MajorDeltaCompactionOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=1.000000
I20260812 06:19:17.457512  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: MajorDeltaCompactionOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.127s	user 0.114s	sys 0.012s 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":964,"lbm_read_time_us":9068,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24789,"lbm_writes_lt_1ms":443,"mutex_wait_us":301,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":19968,"update_count":2000}
I20260812 06:19:17.458213  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=10.126437
I20260812 06:19:17.512084  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.054s	user 0.039s	sys 0.011s Metrics: {"bytes_written":12389541,"delete_count":0,"lbm_write_time_us":20851,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1510}
I20260812 06:19:17.512607  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=2.188937
I20260812 06:19:17.546274  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.033s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4020609,"delete_count":0,"lbm_write_time_us":6266,"lbm_writes_lt_1ms":101,"reinsert_count":0,"update_count":490}
I20260812 06:19:17.546814  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=2.188937
I20260812 06:19:17.558671  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.012s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4576,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:17.559185  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling MajorDeltaCompactionOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=1.000000
I20260812 06:19:17.765970  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: MajorDeltaCompactionOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.207s	user 0.124s	sys 0.075s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774809,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":9747,"dirs.run_cpu_time_us":1490,"dirs.run_wall_time_us":15492,"lbm_read_time_us":13102,"lbm_reads_lt_1ms":573,"lbm_write_time_us":33567,"lbm_writes_lt_1ms":543,"mutex_wait_us":5286,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7040,"update_count":2500}
I20260812 06:19:17.766739  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=14.095187
I20260812 06:19:17.831616  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.062s	user 0.036s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21686,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:17.832315  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=2.188937
I20260812 06:19:17.849584  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.017s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6382,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:17.850301  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling MajorDeltaCompactionOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=1.000000
I20260812 06:19:18.058543  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: MajorDeltaCompactionOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.208s	user 0.109s	sys 0.091s 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":1282,"lbm_read_time_us":13961,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32536,"lbm_writes_lt_1ms":543,"mutex_wait_us":418,"peak_mem_usage":63115900,"reinsert_count":0,"thread_start_us":90,"threads_started":1,"update_count":2500}
I20260812 06:19:18.059356  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=14.095187
I20260812 06:19:18.128321  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.069s	user 0.040s	sys 0.025s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24991,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:18.129045  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=2.188937
I20260812 06:19:18.141177  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4694,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:18.141700  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling MajorDeltaCompactionOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=1.000000
I20260812 06:19:18.338760  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: MajorDeltaCompactionOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.197s	user 0.108s	sys 0.077s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":995,"lbm_read_time_us":13364,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29049,"lbm_writes_lt_1ms":543,"mutex_wait_us":322,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6144,"update_count":2500}
I20260812 06:19:18.339402  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=14.095187
I20260812 06:19:18.402000  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.062s	user 0.032s	sys 0.028s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":27182,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:18.402609  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=2.188937
I20260812 06:19:18.415639  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.013s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4769,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:18.416206  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling FlushMRSOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=1.000000
I20260812 06:19:18.455286  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: FlushMRSOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.039s	user 0.032s	sys 0.005s Metrics: {"bytes_written":1316413,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":254,"dirs.run_wall_time_us":1304,"drs_written":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2659,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:19:18.455925  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling LogGCOp(4222e42b4cd64d61a9e751959bc02c2d): free 128867398 bytes of WAL
I20260812 06:19:18.456190  5492 log_reader.cc:385] T 4222e42b4cd64d61a9e751959bc02c2d: removed 13 log segments from log reader
I20260812 06:19:18.456260  5492 log.cc:1079] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/4222e42b4cd64d61a9e751959bc02c2d/wal-000000003 (ops 12-16)
I20260812 06:19:18.456317  5492 log.cc:1079] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/4222e42b4cd64d61a9e751959bc02c2d/wal-000000004 (ops 17-21)
I20260812 06:19:18.456355  5492 log.cc:1079] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/4222e42b4cd64d61a9e751959bc02c2d/wal-000000005 (ops 22-26)
I20260812 06:19:18.456396  5492 log.cc:1079] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/4222e42b4cd64d61a9e751959bc02c2d/wal-000000006 (ops 27-30)
I20260812 06:19:18.456436  5492 log.cc:1079] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/4222e42b4cd64d61a9e751959bc02c2d/wal-000000007 (ops 31-35)
I20260812 06:19:18.456475  5492 log.cc:1079] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/4222e42b4cd64d61a9e751959bc02c2d/wal-000000008 (ops 36-40)
I20260812 06:19:18.456521  5492 log.cc:1079] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/4222e42b4cd64d61a9e751959bc02c2d/wal-000000009 (ops 41-44)
I20260812 06:19:18.456559  5492 log.cc:1079] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/4222e42b4cd64d61a9e751959bc02c2d/wal-000000010 (ops 45-49)
I20260812 06:19:18.456594  5492 log.cc:1079] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/4222e42b4cd64d61a9e751959bc02c2d/wal-000000011 (ops 50-54)
I20260812 06:19:18.456632  5492 log.cc:1079] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/4222e42b4cd64d61a9e751959bc02c2d/wal-000000012 (ops 55-58)
I20260812 06:19:18.456672  5492 log.cc:1079] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/4222e42b4cd64d61a9e751959bc02c2d/wal-000000013 (ops 59-63)
I20260812 06:19:18.456712  5492 log.cc:1079] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/4222e42b4cd64d61a9e751959bc02c2d/wal-000000014 (ops 64-68)
I20260812 06:19:18.456758  5492 log.cc:1079] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/4222e42b4cd64d61a9e751959bc02c2d/wal-000000015 (ops 69-73)
I20260812 06:19:18.485029  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: LogGCOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.029s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:18.485579  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=2.188937
I20260812 06:19:18.508255  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.022s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6316,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:18.508718  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=2.188937
I20260812 06:19:18.520197  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4106,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:18.520867  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling UndoDeltaBlockGCOp(4222e42b4cd64d61a9e751959bc02c2d): 492 bytes on disk
I20260812 06:19:18.521590  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: UndoDeltaBlockGCOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":136,"lbm_reads_lt_1ms":4}
I20260812 06:19:18.522511  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling MajorDeltaCompactionOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=1.000000
I20260812 06:19:18.798036  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: MajorDeltaCompactionOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.275s	user 0.163s	sys 0.100s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979751,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":577,"lbm_read_time_us":18211,"lbm_reads_lt_1ms":774,"lbm_write_time_us":44117,"lbm_writes_lt_1ms":743,"mutex_wait_us":51,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":4864,"thread_start_us":89,"threads_started":1,"update_count":3500}
I20260812 06:19:18.798852  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=22.032687
I20260812 06:19:18.872717  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.074s	user 0.043s	sys 0.017s Metrics: {"bytes_written":24614720,"delete_count":0,"lbm_write_time_us":28410,"lbm_writes_lt_1ms":603,"reinsert_count":0,"update_count":3000}
I20260812 06:19:18.873277  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=2.188937
I20260812 06:19:18.885841  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.012s	user 0.009s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4477,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:18.886448  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling MajorDeltaCompactionOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=1.000000
I20260812 06:19:19.238533  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: MajorDeltaCompactionOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.352s	user 0.231s	sys 0.083s Metrics: {"cfile_cache_miss":732,"cfile_cache_miss_bytes":32979507,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":896,"lbm_read_time_us":15610,"lbm_reads_lt_1ms":772,"lbm_write_time_us":70218,"lbm_writes_lt_1ms":743,"mutex_wait_us":180,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":24832,"update_count":3500}
I20260812 06:19:19.239688  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=18.063937
I20260812 06:19:19.383137  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.143s	user 0.103s	sys 0.021s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":74643,"lbm_writes_1-10_ms":1,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":501,"reinsert_count":0,"update_count":2500}
I20260812 06:19:19.384197  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=2.188937
I20260812 06:19:19.414806  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.029s	user 0.011s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6612,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:19.415315  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=2.188937
I20260812 06:19:19.426126  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3988,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:19.426606  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling MajorDeltaCompactionOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=1.000000
I20260812 06:19:19.640959  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: MajorDeltaCompactionOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.214s	user 0.137s	sys 0.076s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32979633,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":685,"lbm_read_time_us":14629,"lbm_reads_lt_1ms":773,"lbm_write_time_us":37535,"lbm_writes_lt_1ms":743,"mutex_wait_us":382,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":3500}
I20260812 06:19:19.641482  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=18.063937
I20260812 06:19:19.704319  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.063s	user 0.032s	sys 0.023s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":25939,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:19.704843  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=3.181125
I20260812 06:19:19.722796  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.018s	user 0.012s	sys 0.005s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":7249,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:19.723351  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=2.188937
I20260812 06:19:19.733330  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.010s	user 0.007s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3700,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:19.734007  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling MajorDeltaCompactionOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=1.000000
I20260812 06:19:19.915827  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: MajorDeltaCompactionOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.182s	user 0.141s	sys 0.041s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32979623,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":74,"lbm_read_time_us":13055,"lbm_reads_lt_1ms":773,"lbm_write_time_us":39472,"lbm_writes_lt_1ms":743,"mutex_wait_us":55,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":14592,"update_count":3500}
I20260812 06:19:19.916960  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=14.095187
I20260812 06:19:19.967204  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.050s	user 0.048s	sys 0.000s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21930,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:19.968019  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=2.188937
I20260812 06:19:19.996335  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.028s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5914,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:19.996837  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=2.188937
I20260812 06:19:20.011953  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5453,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:20.012619  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling FlushMRSOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=1.000000
I20260812 06:19:20.046859  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: FlushMRSOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.034s	user 0.025s	sys 0.008s Metrics: {"bytes_written":1193507,"cfile_init":1,"dirs.queue_time_us":86,"dirs.run_cpu_time_us":255,"dirs.run_wall_time_us":1362,"drs_written":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1834,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:20.047657  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling LogGCOp(4222e42b4cd64d61a9e751959bc02c2d): free 120553443 bytes of WAL
I20260812 06:19:20.047922  5492 log_reader.cc:385] T 4222e42b4cd64d61a9e751959bc02c2d: removed 12 log segments from log reader
I20260812 06:19:20.047991  5492 log.cc:1079] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/4222e42b4cd64d61a9e751959bc02c2d/wal-000000016 (ops 74-78)
I20260812 06:19:20.048050  5492 log.cc:1079] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/4222e42b4cd64d61a9e751959bc02c2d/wal-000000017 (ops 79-83)
I20260812 06:19:20.048110  5492 log.cc:1079] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/4222e42b4cd64d61a9e751959bc02c2d/wal-000000018 (ops 84-88)
I20260812 06:19:20.048153  5492 log.cc:1079] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/4222e42b4cd64d61a9e751959bc02c2d/wal-000000019 (ops 89-93)
I20260812 06:19:20.048192  5492 log.cc:1079] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/4222e42b4cd64d61a9e751959bc02c2d/wal-000000020 (ops 94-98)
I20260812 06:19:20.048228  5492 log.cc:1079] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/4222e42b4cd64d61a9e751959bc02c2d/wal-000000021 (ops 99-102)
I20260812 06:19:20.048275  5492 log.cc:1079] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/4222e42b4cd64d61a9e751959bc02c2d/wal-000000022 (ops 103-107)
I20260812 06:19:20.048316  5492 log.cc:1079] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/4222e42b4cd64d61a9e751959bc02c2d/wal-000000023 (ops 108-112)
I20260812 06:19:20.048353  5492 log.cc:1079] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/4222e42b4cd64d61a9e751959bc02c2d/wal-000000024 (ops 113-116)
I20260812 06:19:20.048391  5492 log.cc:1079] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/4222e42b4cd64d61a9e751959bc02c2d/wal-000000025 (ops 117-121)
I20260812 06:19:20.048431  5492 log.cc:1079] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/4222e42b4cd64d61a9e751959bc02c2d/wal-000000026 (ops 122-126)
I20260812 06:19:20.048471  5492 log.cc:1079] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/4222e42b4cd64d61a9e751959bc02c2d/wal-000000027 (ops 127-131)
I20260812 06:19:20.077028  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: LogGCOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.029s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:20.077473  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling UndoDeltaBlockGCOp(4222e42b4cd64d61a9e751959bc02c2d): 463 bytes on disk
I20260812 06:19:20.077965  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: UndoDeltaBlockGCOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":75,"lbm_reads_lt_1ms":4}
I20260812 06:19:20.078545  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=3.181125
I20260812 06:19:20.098590  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.020s	user 0.015s	sys 0.003s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":7371,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:20.099113  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=2.188937
I20260812 06:19:20.109133  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3756,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:20.109656  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling MajorDeltaCompactionOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=1.000000
I20260812 06:19:20.338619  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: MajorDeltaCompactionOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.228s	user 0.154s	sys 0.068s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37082266,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":818,"lbm_read_time_us":15318,"lbm_reads_lt_1ms":875,"lbm_write_time_us":49217,"lbm_writes_lt_1ms":843,"mutex_wait_us":319,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":2944,"thread_start_us":81,"threads_started":1,"update_count":4000}
I20260812 06:19:20.339388  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=18.063937
I20260812 06:19:20.409138  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.070s	user 0.035s	sys 0.031s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":31040,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:20.409968  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=2.188937
I20260812 06:19:20.434881  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.025s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5490,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:20.435343  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling MajorDeltaCompactionOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=1.000000
I20260812 06:19:20.638018  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: MajorDeltaCompactionOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.202s	user 0.157s	sys 0.045s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877101,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":356,"lbm_read_time_us":14211,"lbm_reads_lt_1ms":664,"lbm_write_time_us":36075,"lbm_writes_lt_1ms":643,"mutex_wait_us":45,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":3000}
I20260812 06:19:20.638649  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=18.063937
I20260812 06:19:20.717095  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.078s	user 0.023s	sys 0.051s Metrics: {"bytes_written":20512314,"delete_count":0,"lbm_write_time_us":30578,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:19:20.717689  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=2.188937
I20260812 06:19:20.740865  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.023s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7123,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:20.741465  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=2.188937
I20260812 06:19:20.752269  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4119,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:20.752862  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling MajorDeltaCompactionOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=1.000000
I20260812 06:19:20.981463  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: MajorDeltaCompactionOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.228s	user 0.145s	sys 0.080s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32979632,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"lbm_read_time_us":15492,"lbm_reads_lt_1ms":773,"lbm_write_time_us":37636,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"update_count":3500}
I20260812 06:19:20.982481  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=18.063937
I20260812 06:19:21.042547  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.059s	user 0.052s	sys 0.004s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":25331,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:21.043458  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=2.188937
I20260812 06:19:21.063764  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.020s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6101,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:21.064288  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling MajorDeltaCompactionOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=1.000000
I20260812 06:19:21.293004  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: MajorDeltaCompactionOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.229s	user 0.121s	sys 0.101s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":945,"lbm_read_time_us":14497,"lbm_reads_lt_1ms":664,"lbm_write_time_us":38969,"lbm_writes_lt_1ms":643,"mutex_wait_us":366,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":17792,"update_count":3000}
I20260812 06:19:21.293737  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=18.063937
I20260812 06:19:21.368528  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.075s	user 0.040s	sys 0.021s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":30758,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:19:21.369053  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=2.188937
I20260812 06:19:21.382571  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.013s	user 0.002s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4800,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:21.383045  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling MajorDeltaCompactionOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=1.000000
I20260812 06:19:21.588433  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: MajorDeltaCompactionOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.205s	user 0.137s	sys 0.068s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877103,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":150,"lbm_read_time_us":14597,"lbm_reads_lt_1ms":672,"lbm_write_time_us":35565,"lbm_writes_lt_1ms":643,"mutex_wait_us":24,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12928,"update_count":3000}
I20260812 06:19:21.589250  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=14.095187
I20260812 06:19:21.641153  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.052s	user 0.028s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21691,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:21.641992  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=3.181125
I20260812 06:19:21.662693  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.021s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":5129,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:21.663187  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=2.188937
I20260812 06:19:21.673214  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.010s	user 0.005s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3696,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:21.673764  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling FlushMRSOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=1.000000
I20260812 06:19:21.709872  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: FlushMRSOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.036s	user 0.031s	sys 0.005s Metrics: {"bytes_written":1357582,"cfile_init":1,"dirs.queue_time_us":53,"dirs.run_cpu_time_us":208,"dirs.run_wall_time_us":1595,"drs_written":1,"lbm_read_time_us":96,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2719,"lbm_writes_lt_1ms":44,"peak_mem_usage":0,"rows_written":33}
I20260812 06:19:21.710616  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling LogGCOp(4222e42b4cd64d61a9e751959bc02c2d): free 141338730 bytes of WAL
I20260812 06:19:21.710868  5492 log_reader.cc:385] T 4222e42b4cd64d61a9e751959bc02c2d: removed 14 log segments from log reader
I20260812 06:19:21.710915  5492 log.cc:1079] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/4222e42b4cd64d61a9e751959bc02c2d/wal-000000028 (ops 132-136)
I20260812 06:19:21.710945  5492 log.cc:1079] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/4222e42b4cd64d61a9e751959bc02c2d/wal-000000029 (ops 137-141)
I20260812 06:19:21.711006  5492 log.cc:1079] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/4222e42b4cd64d61a9e751959bc02c2d/wal-000000030 (ops 142-146)
I20260812 06:19:21.711054  5492 log.cc:1079] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/4222e42b4cd64d61a9e751959bc02c2d/wal-000000031 (ops 147-150)
I20260812 06:19:21.711112  5492 log.cc:1079] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/4222e42b4cd64d61a9e751959bc02c2d/wal-000000032 (ops 151-155)
I20260812 06:19:21.711164  5492 log.cc:1079] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/4222e42b4cd64d61a9e751959bc02c2d/wal-000000033 (ops 156-160)
I20260812 06:19:21.711202  5492 log.cc:1079] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/4222e42b4cd64d61a9e751959bc02c2d/wal-000000034 (ops 161-165)
I20260812 06:19:21.711241  5492 log.cc:1079] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/4222e42b4cd64d61a9e751959bc02c2d/wal-000000035 (ops 166-170)
I20260812 06:19:21.711279  5492 log.cc:1079] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/4222e42b4cd64d61a9e751959bc02c2d/wal-000000036 (ops 171-175)
I20260812 06:19:21.711321  5492 log.cc:1079] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/4222e42b4cd64d61a9e751959bc02c2d/wal-000000037 (ops 176-180)
I20260812 06:19:21.711360  5492 log.cc:1079] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/4222e42b4cd64d61a9e751959bc02c2d/wal-000000038 (ops 181-184)
I20260812 06:19:21.711398  5492 log.cc:1079] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/4222e42b4cd64d61a9e751959bc02c2d/wal-000000039 (ops 185-189)
I20260812 06:19:21.711436  5492 log.cc:1079] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/4222e42b4cd64d61a9e751959bc02c2d/wal-000000040 (ops 190-194)
I20260812 06:19:21.711475  5492 log.cc:1079] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c: Deleting log segment in path: /tmp/dist-test-taskyA12eL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515550972950-5162-0/minicluster-data/ts-0-root/wals/4222e42b4cd64d61a9e751959bc02c2d/wal-000000041 (ops 195-199)
I20260812 06:19:21.743582  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: LogGCOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.033s	user 0.000s	sys 0.031s Metrics: {}
I20260812 06:19:21.744096  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling UndoDeltaBlockGCOp(4222e42b4cd64d61a9e751959bc02c2d): 507 bytes on disk
I20260812 06:19:21.744978  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: UndoDeltaBlockGCOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4}
I20260812 06:19:21.745565  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=3.181125
I20260812 06:19:21.758780  5162 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.150s	user 1.903s	sys 0.148s
I20260812 06:19:21.760437  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.015s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":4860,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:21.761186  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=2.188937
I20260812 06:19:21.771674  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: FlushDeltaMemStoresOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.010s	user 0.000s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4277,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:21.772145  5562 maintenance_manager.cc:419] P c0766134a9a143f3aee36349e36dde0c: Scheduling MajorDeltaCompactionOp(4222e42b4cd64d61a9e751959bc02c2d): perf score=1.000000
I20260812 06:19:21.850036  5162 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.091s	user 0.003s	sys 0.000s
I20260812 06:19:21.850598  5162 tablet_server.cc:179] TabletServer@127.5.10.129:0 shutting down...
I20260812 06:19:21.960116  5492 maintenance_manager.cc:643] P c0766134a9a143f3aee36349e36dde0c: MajorDeltaCompactionOp(4222e42b4cd64d61a9e751959bc02c2d) complete. Timing: real 0.188s	user 0.118s	sys 0.069s Metrics: {"cfile_cache_hit":266,"cfile_cache_hit_bytes":10754658,"cfile_cache_miss":569,"cfile_cache_miss_bytes":26327595,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":826,"lbm_read_time_us":10987,"lbm_reads_lt_1ms":601,"lbm_write_time_us":39178,"lbm_writes_lt_1ms":843,"mutex_wait_us":60,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":44672,"thread_start_us":96,"threads_started":1,"update_count":4000}
I20260812 06:19:21.961547  5162 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:21.961860  5162 tablet_replica.cc:333] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c: stopping tablet replica
I20260812 06:19:21.962041  5162 raft_consensus.cc:2243] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:21.962237  5162 raft_consensus.cc:2272] T 4222e42b4cd64d61a9e751959bc02c2d P c0766134a9a143f3aee36349e36dde0c [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:21.967622  5162 tablet_server.cc:196] TabletServer@127.5.10.129:0 shutdown complete.
I20260812 06:19:22.033061  5162 master.cc:562] Master@127.5.10.190:34801 shutting down...
I20260812 06:19:22.036752  5162 raft_consensus.cc:2243] T 00000000000000000000000000000000 P eeb0899c514745fd9c7b9ebe901d57e2 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:22.036957  5162 raft_consensus.cc:2272] T 00000000000000000000000000000000 P eeb0899c514745fd9c7b9ebe901d57e2 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:22.037060  5162 tablet_replica.cc:333] T 00000000000000000000000000000000 P eeb0899c514745fd9c7b9ebe901d57e2: stopping tablet replica
I20260812 06:19:22.049453  5162 master.cc:584] Master@127.5.10.190:34801 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5735 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11155 ms total)

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