[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:20:20.532325  8944 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.8.188.62:44689
I20260812 06:20:20.533387  8944 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:20:20.534017  8944 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:20.540416  8955 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:20:20.540503  8953 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:20.540416  8957 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:20.541332  8944 server_base.cc:1061] running on GCE node
I20260812 06:20:20.541777  8944 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:20.541868  8944 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:20.541898  8944 hybrid_clock.cc:648] HybridClock initialized: now 1786515620541895 us; error 0 us; skew 500 ppm
I20260812 06:20:20.543839  8944 webserver.cc:533] Webserver started at http://127.8.188.62:45875/ using document root <none> and password file <none>
I20260812 06:20:20.544343  8944 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:20.544409  8944 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:20.544605  8944 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:20.546339  8944 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620521417-8944-0/minicluster-data/master-0-root/instance:
uuid: "42db54eae18c4f73873dd2a42e92d669"
format_stamp: "Formatted at 2026-08-12 06:20:20 on dist-test-slave-7nm7"
I20260812 06:20:20.550123  8944 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:20:20.552338  8963 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:20.553417  8944 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:20.553555  8944 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620521417-8944-0/minicluster-data/master-0-root
uuid: "42db54eae18c4f73873dd2a42e92d669"
format_stamp: "Formatted at 2026-08-12 06:20:20 on dist-test-slave-7nm7"
I20260812 06:20:20.553665  8944 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620521417-8944-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620521417-8944-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620521417-8944-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:20.572714  8944 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:20.573397  8944 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:20:20.573593  8944 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:20.581760  8944 rpc_server.cc:307] RPC server started. Bound to: 127.8.188.62:44689
I20260812 06:20:20.581769  9058 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.8.188.62:44689 every 8 connection(s)
I20260812 06:20:20.584954  9060 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:20.593261  9060 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 42db54eae18c4f73873dd2a42e92d669: Bootstrap starting.
I20260812 06:20:20.595621  9060 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 42db54eae18c4f73873dd2a42e92d669: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:20.596493  9060 log.cc:826] T 00000000000000000000000000000000 P 42db54eae18c4f73873dd2a42e92d669: Log is configured to *not* fsync() on all Append() calls
I20260812 06:20:20.598165  9060 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 42db54eae18c4f73873dd2a42e92d669: No bootstrap required, opened a new log
I20260812 06:20:20.600903  9060 raft_consensus.cc:359] T 00000000000000000000000000000000 P 42db54eae18c4f73873dd2a42e92d669 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "42db54eae18c4f73873dd2a42e92d669" member_type: VOTER }
I20260812 06:20:20.601065  9060 raft_consensus.cc:385] T 00000000000000000000000000000000 P 42db54eae18c4f73873dd2a42e92d669 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:20.601157  9060 raft_consensus.cc:740] T 00000000000000000000000000000000 P 42db54eae18c4f73873dd2a42e92d669 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 42db54eae18c4f73873dd2a42e92d669, State: Initialized, Role: FOLLOWER
I20260812 06:20:20.601774  9060 consensus_queue.cc:260] T 00000000000000000000000000000000 P 42db54eae18c4f73873dd2a42e92d669 [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: "42db54eae18c4f73873dd2a42e92d669" member_type: VOTER }
I20260812 06:20:20.601951  9060 raft_consensus.cc:399] T 00000000000000000000000000000000 P 42db54eae18c4f73873dd2a42e92d669 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:20.602028  9060 raft_consensus.cc:493] T 00000000000000000000000000000000 P 42db54eae18c4f73873dd2a42e92d669 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:20.602159  9060 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 42db54eae18c4f73873dd2a42e92d669 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:20.602981  9060 raft_consensus.cc:515] T 00000000000000000000000000000000 P 42db54eae18c4f73873dd2a42e92d669 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "42db54eae18c4f73873dd2a42e92d669" member_type: VOTER }
I20260812 06:20:20.603431  9060 leader_election.cc:304] T 00000000000000000000000000000000 P 42db54eae18c4f73873dd2a42e92d669 [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: 42db54eae18c4f73873dd2a42e92d669; no voters: 
I20260812 06:20:20.603808  9060 leader_election.cc:290] T 00000000000000000000000000000000 P 42db54eae18c4f73873dd2a42e92d669 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:20.603951  9064 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 42db54eae18c4f73873dd2a42e92d669 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:20.604236  9064 raft_consensus.cc:697] T 00000000000000000000000000000000 P 42db54eae18c4f73873dd2a42e92d669 [term 1 LEADER]: Becoming Leader. State: Replica: 42db54eae18c4f73873dd2a42e92d669, State: Running, Role: LEADER
I20260812 06:20:20.604653  9064 consensus_queue.cc:237] T 00000000000000000000000000000000 P 42db54eae18c4f73873dd2a42e92d669 [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: "42db54eae18c4f73873dd2a42e92d669" member_type: VOTER }
I20260812 06:20:20.604849  9060 sys_catalog.cc:565] T 00000000000000000000000000000000 P 42db54eae18c4f73873dd2a42e92d669 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:20.606520  9065 sys_catalog.cc:455] T 00000000000000000000000000000000 P 42db54eae18c4f73873dd2a42e92d669 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "42db54eae18c4f73873dd2a42e92d669" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "42db54eae18c4f73873dd2a42e92d669" member_type: VOTER } }
I20260812 06:20:20.606632  9065 sys_catalog.cc:458] T 00000000000000000000000000000000 P 42db54eae18c4f73873dd2a42e92d669 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:20.606914  9066 sys_catalog.cc:455] T 00000000000000000000000000000000 P 42db54eae18c4f73873dd2a42e92d669 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 42db54eae18c4f73873dd2a42e92d669. Latest consensus state: current_term: 1 leader_uuid: "42db54eae18c4f73873dd2a42e92d669" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "42db54eae18c4f73873dd2a42e92d669" member_type: VOTER } }
I20260812 06:20:20.606990  9076 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:20.607007  9066 sys_catalog.cc:458] T 00000000000000000000000000000000 P 42db54eae18c4f73873dd2a42e92d669 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:20.609531  9076 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:20.609776  8944 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:20.614030  9076 catalog_manager.cc:1383] Generated new cluster ID: 1f980156554e4b7f8af7aa188284e4c8
I20260812 06:20:20.614099  9076 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:20.626883  9076 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:20.627797  9076 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:20.632862  9076 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 42db54eae18c4f73873dd2a42e92d669: Generated new TSK 0
I20260812 06:20:20.633478  9076 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:20.642513  8944 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:20.645524  9091 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:20:20.645599  9095 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:20.645691  9089 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:20.645817  8944 server_base.cc:1061] running on GCE node
I20260812 06:20:20.646173  8944 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:20.646238  8944 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:20.646293  8944 hybrid_clock.cc:648] HybridClock initialized: now 1786515620646291 us; error 0 us; skew 500 ppm
I20260812 06:20:20.647269  8944 webserver.cc:533] Webserver started at http://127.8.188.1:39707/ using document root <none> and password file <none>
I20260812 06:20:20.647440  8944 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:20.647523  8944 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:20.647603  8944 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:20.647979  8944 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620521417-8944-0/minicluster-data/ts-0-root/instance:
uuid: "36f1622a576b42249b44dd508b5ac6ba"
format_stamp: "Formatted at 2026-08-12 06:20:20 on dist-test-slave-7nm7"
I20260812 06:20:20.649515  8944 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:20:20.650570  9101 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:20.650815  8944 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:20.650887  8944 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620521417-8944-0/minicluster-data/ts-0-root
uuid: "36f1622a576b42249b44dd508b5ac6ba"
format_stamp: "Formatted at 2026-08-12 06:20:20 on dist-test-slave-7nm7"
I20260812 06:20:20.650974  8944 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620521417-8944-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620521417-8944-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620521417-8944-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:20.656250  8944 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:20.656632  8944 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:20.657037  8944 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:20.657871  8944 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:20.657922  8944 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:20.657990  8944 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:20.658027  8944 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:20.664654  8944 rpc_server.cc:307] RPC server started. Bound to: 127.8.188.1:33787
I20260812 06:20:20.664691  9212 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.8.188.1:33787 every 8 connection(s)
I20260812 06:20:20.680444  9214 heartbeater.cc:344] Connected to a master server at 127.8.188.62:44689
I20260812 06:20:20.680713  9214 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:20.681181  9214 heartbeater.cc:507] Master 127.8.188.62:44689 requested a full tablet report, sending...
I20260812 06:20:20.682749  8990 ts_manager.cc:194] Registered new tserver with Master: 36f1622a576b42249b44dd508b5ac6ba (127.8.188.1:33787)
I20260812 06:20:20.683101  8944 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.017833152s
I20260812 06:20:20.684250  8990 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:58648
I20260812 06:20:20.692691  8990 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:58662:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:20:20.706933  9156 tablet_service.cc:1511] Processing CreateTablet for tablet 78f64aa9f0fb414b9f19e501550ae4c0 (DEFAULT_TABLE table=heavy-update-compaction-test [id=8e6930020aa647488e4f90268edd768a]), partition=
I20260812 06:20:20.707433  9156 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 78f64aa9f0fb414b9f19e501550ae4c0. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:20.709887  9232 tablet_bootstrap.cc:492] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba: Bootstrap starting.
I20260812 06:20:20.710870  9232 tablet_bootstrap.cc:654] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:20.711963  9232 tablet_bootstrap.cc:492] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba: No bootstrap required, opened a new log
I20260812 06:20:20.712070  9232 ts_tablet_manager.cc:1403] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:20.712503  9232 raft_consensus.cc:359] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "36f1622a576b42249b44dd508b5ac6ba" member_type: VOTER last_known_addr { host: "127.8.188.1" port: 33787 } }
I20260812 06:20:20.712607  9232 raft_consensus.cc:385] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:20.712630  9232 raft_consensus.cc:740] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 36f1622a576b42249b44dd508b5ac6ba, State: Initialized, Role: FOLLOWER
I20260812 06:20:20.712816  9232 consensus_queue.cc:260] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba [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: "36f1622a576b42249b44dd508b5ac6ba" member_type: VOTER last_known_addr { host: "127.8.188.1" port: 33787 } }
I20260812 06:20:20.712900  9232 raft_consensus.cc:399] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:20.712949  9232 raft_consensus.cc:493] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:20.712999  9232 raft_consensus.cc:3060] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:20.713915  9232 raft_consensus.cc:515] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "36f1622a576b42249b44dd508b5ac6ba" member_type: VOTER last_known_addr { host: "127.8.188.1" port: 33787 } }
I20260812 06:20:20.714056  9232 leader_election.cc:304] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba [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: 36f1622a576b42249b44dd508b5ac6ba; no voters: 
I20260812 06:20:20.714270  9232 leader_election.cc:290] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:20.714519  9235 raft_consensus.cc:2804] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:20.714757  9232 ts_tablet_manager.cc:1434] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba: Time spent starting tablet: real 0.003s	user 0.001s	sys 0.002s
I20260812 06:20:20.714797  9235 raft_consensus.cc:697] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba [term 1 LEADER]: Becoming Leader. State: Replica: 36f1622a576b42249b44dd508b5ac6ba, State: Running, Role: LEADER
I20260812 06:20:20.714974  9214 heartbeater.cc:499] Master 127.8.188.62:44689 was elected leader, sending a full tablet report...
I20260812 06:20:20.714977  9235 consensus_queue.cc:237] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba [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: "36f1622a576b42249b44dd508b5ac6ba" member_type: VOTER last_known_addr { host: "127.8.188.1" port: 33787 } }
I20260812 06:20:20.717721  8990 catalog_manager.cc:5719] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba reported cstate change: term changed from 0 to 1, leader changed from <none> to 36f1622a576b42249b44dd508b5ac6ba (127.8.188.1). New cstate: current_term: 1 leader_uuid: "36f1622a576b42249b44dd508b5ac6ba" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "36f1622a576b42249b44dd508b5ac6ba" member_type: VOTER last_known_addr { host: "127.8.188.1" port: 33787 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:20.787355  8944 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.061s	user 0.011s	sys 0.015s
I20260812 06:20:20.915724  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling FlushMRSOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=15.086190
I20260812 06:20:21.087661  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: FlushMRSOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.172s	user 0.141s	sys 0.020s Metrics: {"bytes_written":11897249,"cfile_init":1,"compiler_manager_pool.queue_time_us":272,"delete_count":0,"dirs.queue_time_us":42,"dirs.run_cpu_time_us":222,"dirs.run_wall_time_us":747,"drs_written":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4,"lbm_write_time_us":43975,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":157,"threads_started":1,"update_count":1450}
I20260812 06:20:21.088831  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling LogGCOp(78f64aa9f0fb414b9f19e501550ae4c0): free 20743880 bytes of WAL
I20260812 06:20:21.089185  9110 log_reader.cc:385] T 78f64aa9f0fb414b9f19e501550ae4c0: removed 2 log segments from log reader
I20260812 06:20:21.089280  9110 log.cc:1079] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/78f64aa9f0fb414b9f19e501550ae4c0/wal-000000001 (ops 1-6)
I20260812 06:20:21.089356  9110 log.cc:1079] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/78f64aa9f0fb414b9f19e501550ae4c0/wal-000000002 (ops 7-11)
I20260812 06:20:21.093849  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: LogGCOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.005s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:20:21.094300  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling UndoDeltaBlockGCOp(78f64aa9f0fb414b9f19e501550ae4c0): 12719217 bytes on disk
I20260812 06:20:21.094911  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: UndoDeltaBlockGCOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4}
I20260812 06:20:21.095335  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=2.188937
I20260812 06:20:21.118578  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.023s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":9858,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":102,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.119027  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling MajorDeltaCompactionOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=1.000000
I20260812 06:20:21.249213  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: MajorDeltaCompactionOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.130s	user 0.085s	sys 0.044s Metrics: {"cfile_cache_miss":422,"cfile_cache_miss_bytes":20262036,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":649,"lbm_read_time_us":9466,"lbm_reads_lt_1ms":450,"lbm_write_time_us":26760,"lbm_writes_lt_1ms":433,"mutex_wait_us":35,"peak_mem_usage":49238594,"reinsert_count":0,"spinlock_wait_cycles":14592,"thread_start_us":276,"threads_started":5,"update_count":1950}
I20260812 06:20:21.249766  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=10.126437
I20260812 06:20:21.307920  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.058s	user 0.036s	sys 0.011s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":21430,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:21.308523  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=2.188937
I20260812 06:20:21.324565  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.016s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6392,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.325080  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling MajorDeltaCompactionOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=1.000000
I20260812 06:20:21.470453  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: MajorDeltaCompactionOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.145s	user 0.127s	sys 0.016s 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":693,"lbm_read_time_us":14085,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27574,"lbm_writes_lt_1ms":443,"mutex_wait_us":44,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3584,"update_count":2000}
I20260812 06:20:21.471148  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=10.126437
I20260812 06:20:21.512308  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.041s	user 0.027s	sys 0.012s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":18909,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:21.512791  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=2.188937
I20260812 06:20:21.534265  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.021s	user 0.014s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6571,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":500}
I20260812 06:20:21.534859  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling MajorDeltaCompactionOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=1.000000
I20260812 06:20:21.680948  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: MajorDeltaCompactionOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.146s	user 0.120s	sys 0.014s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672280,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":956,"lbm_read_time_us":10123,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27815,"lbm_writes_lt_1ms":443,"mutex_wait_us":378,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2000}
I20260812 06:20:21.681526  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=14.095187
I20260812 06:20:21.749876  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.068s	user 0.041s	sys 0.017s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":28227,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:21.750461  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=2.188937
I20260812 06:20:21.764014  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.013s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5154,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.764447  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling MajorDeltaCompactionOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=1.000000
I20260812 06:20:21.950302  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: MajorDeltaCompactionOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.186s	user 0.131s	sys 0.050s 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":298,"lbm_read_time_us":15156,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34053,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2500}
I20260812 06:20:21.950896  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=14.095187
I20260812 06:20:22.024549  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.073s	user 0.041s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":26277,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:22.025151  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=2.188937
I20260812 06:20:22.036064  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4211,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.036628  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling MajorDeltaCompactionOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=1.000000
I20260812 06:20:22.209075  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: MajorDeltaCompactionOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.172s	user 0.135s	sys 0.036s 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":1688,"lbm_read_time_us":15139,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28994,"lbm_writes_lt_1ms":543,"mutex_wait_us":535,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:22.209756  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=10.126437
I20260812 06:20:22.243394  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.033s	user 0.023s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14013,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:22.243832  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=2.188937
I20260812 06:20:22.258071  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5265,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.258765  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling MajorDeltaCompactionOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=1.000000
I20260812 06:20:22.392025  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: MajorDeltaCompactionOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.133s	user 0.104s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":269,"lbm_read_time_us":9696,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26839,"lbm_writes_lt_1ms":443,"mutex_wait_us":39,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3328,"update_count":2000}
I20260812 06:20:22.392541  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=10.126437
I20260812 06:20:22.431689  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.039s	user 0.023s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15453,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:22.432377  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling FlushMRSOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=1.000000
I20260812 06:20:22.479604  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: FlushMRSOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.047s	user 0.024s	sys 0.008s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":53,"dirs.run_cpu_time_us":254,"dirs.run_wall_time_us":1313,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1785,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:22.480405  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling UndoDeltaBlockGCOp(78f64aa9f0fb414b9f19e501550ae4c0): 462 bytes on disk
I20260812 06:20:22.480908  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: UndoDeltaBlockGCOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:20:22.481451  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=3.181125
I20260812 06:20:22.495410  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.014s	user 0.002s	sys 0.009s Metrics: {"bytes_written":4512901,"delete_count":0,"lbm_write_time_us":4701,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:22.495937  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling LogGCOp(78f64aa9f0fb414b9f19e501550ae4c0): free 112239263 bytes of WAL
I20260812 06:20:22.496186  9110 log_reader.cc:385] T 78f64aa9f0fb414b9f19e501550ae4c0: removed 11 log segments from log reader
I20260812 06:20:22.496235  9110 log.cc:1079] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/78f64aa9f0fb414b9f19e501550ae4c0/wal-000000003 (ops 12-16)
I20260812 06:20:22.496269  9110 log.cc:1079] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/78f64aa9f0fb414b9f19e501550ae4c0/wal-000000004 (ops 17-20)
I20260812 06:20:22.496344  9110 log.cc:1079] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/78f64aa9f0fb414b9f19e501550ae4c0/wal-000000005 (ops 21-25)
I20260812 06:20:22.496389  9110 log.cc:1079] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/78f64aa9f0fb414b9f19e501550ae4c0/wal-000000006 (ops 26-30)
I20260812 06:20:22.496435  9110 log.cc:1079] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/78f64aa9f0fb414b9f19e501550ae4c0/wal-000000007 (ops 31-35)
I20260812 06:20:22.496477  9110 log.cc:1079] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/78f64aa9f0fb414b9f19e501550ae4c0/wal-000000008 (ops 36-40)
I20260812 06:20:22.496524  9110 log.cc:1079] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/78f64aa9f0fb414b9f19e501550ae4c0/wal-000000009 (ops 41-45)
I20260812 06:20:22.496570  9110 log.cc:1079] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/78f64aa9f0fb414b9f19e501550ae4c0/wal-000000010 (ops 46-50)
I20260812 06:20:22.496614  9110 log.cc:1079] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/78f64aa9f0fb414b9f19e501550ae4c0/wal-000000011 (ops 51-55)
I20260812 06:20:22.496658  9110 log.cc:1079] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/78f64aa9f0fb414b9f19e501550ae4c0/wal-000000012 (ops 56-60)
I20260812 06:20:22.496702  9110 log.cc:1079] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/78f64aa9f0fb414b9f19e501550ae4c0/wal-000000013 (ops 61-65)
I20260812 06:20:22.524374  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: LogGCOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.028s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:20:22.524863  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=2.188937
I20260812 06:20:22.540284  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.015s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4539,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:22.540766  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling LogGCOp(78f64aa9f0fb414b9f19e501550ae4c0): free 12017983 bytes of WAL
I20260812 06:20:22.540992  9110 log_reader.cc:385] T 78f64aa9f0fb414b9f19e501550ae4c0: removed 1 log segments from log reader
I20260812 06:20:22.541059  9110 log.cc:1079] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/78f64aa9f0fb414b9f19e501550ae4c0/wal-000000014 (ops 66-70)
I20260812 06:20:22.543622  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: LogGCOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:20:22.543920  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=2.188937
I20260812 06:20:22.557632  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.014s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5312,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.558198  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling MajorDeltaCompactionOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=1.000000
I20260812 06:20:22.748076  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: MajorDeltaCompactionOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.190s	user 0.157s	sys 0.033s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877327,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":599,"lbm_read_time_us":15061,"lbm_reads_lt_1ms":666,"lbm_write_time_us":38991,"lbm_writes_lt_1ms":643,"mutex_wait_us":24,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":28032,"thread_start_us":98,"threads_started":1,"update_count":3000}
I20260812 06:20:22.748775  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=14.095187
I20260812 06:20:22.809365  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.060s	user 0.041s	sys 0.017s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":28143,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:22.809894  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=2.188937
I20260812 06:20:22.824542  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.014s	user 0.009s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5911,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.825037  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling MajorDeltaCompactionOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=1.000000
I20260812 06:20:22.998265  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: MajorDeltaCompactionOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.173s	user 0.133s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":396,"lbm_read_time_us":14035,"lbm_reads_lt_1ms":564,"lbm_write_time_us":33572,"lbm_writes_lt_1ms":543,"mutex_wait_us":60,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:20:22.998843  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=14.095187
I20260812 06:20:23.059310  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.060s	user 0.035s	sys 0.024s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":27896,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:23.059854  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=2.188937
I20260812 06:20:23.073134  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5096,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.073724  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling MajorDeltaCompactionOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=1.000000
I20260812 06:20:23.238940  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: MajorDeltaCompactionOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.165s	user 0.120s	sys 0.039s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":745,"lbm_read_time_us":13775,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30781,"lbm_writes_lt_1ms":543,"mutex_wait_us":378,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:20:23.239602  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=14.095187
I20260812 06:20:23.291344  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.052s	user 0.028s	sys 0.020s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":20977,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:23.292018  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=2.188937
I20260812 06:20:23.307876  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.016s	user 0.013s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6287,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.308441  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling MajorDeltaCompactionOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=1.000000
I20260812 06:20:23.470485  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: MajorDeltaCompactionOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.162s	user 0.111s	sys 0.050s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1440,"lbm_read_time_us":11516,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30892,"lbm_writes_lt_1ms":543,"mutex_wait_us":357,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15104,"update_count":2500}
I20260812 06:20:23.471206  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=10.126437
I20260812 06:20:23.513360  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.042s	user 0.019s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16547,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:23.514043  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=2.188937
I20260812 06:20:23.530839  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.017s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6811,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.531322  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling MajorDeltaCompactionOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=1.000000
I20260812 06:20:23.667184  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: MajorDeltaCompactionOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.136s	user 0.099s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":228,"lbm_read_time_us":10465,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28083,"lbm_writes_lt_1ms":443,"mutex_wait_us":30,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:23.668334  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=10.126437
I20260812 06:20:23.722817  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.053s	user 0.032s	sys 0.020s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":19595,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:23.723425  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=2.188937
I20260812 06:20:23.734429  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4153,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:23.734884  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling MajorDeltaCompactionOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=1.000000
I20260812 06:20:23.883102  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: MajorDeltaCompactionOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.148s	user 0.100s	sys 0.048s 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":191,"lbm_read_time_us":12306,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23944,"lbm_writes_lt_1ms":443,"mutex_wait_us":41,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":106240,"update_count":2000}
I20260812 06:20:23.883898  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=10.126437
I20260812 06:20:23.930725  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.047s	user 0.020s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15911,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:23.931205  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=2.188937
I20260812 06:20:23.942340  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.011s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4335,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.943105  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling FlushMRSOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=1.000000
I20260812 06:20:23.978098  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: FlushMRSOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.035s	user 0.029s	sys 0.004s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":263,"dirs.run_wall_time_us":1299,"drs_written":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2620,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:23.978844  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling LogGCOp(78f64aa9f0fb414b9f19e501550ae4c0): free 112239316 bytes of WAL
I20260812 06:20:23.979065  9110 log_reader.cc:385] T 78f64aa9f0fb414b9f19e501550ae4c0: removed 11 log segments from log reader
I20260812 06:20:23.979110  9110 log.cc:1079] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/78f64aa9f0fb414b9f19e501550ae4c0/wal-000000015 (ops 71-75)
I20260812 06:20:23.979146  9110 log.cc:1079] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/78f64aa9f0fb414b9f19e501550ae4c0/wal-000000016 (ops 76-80)
I20260812 06:20:23.979204  9110 log.cc:1079] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/78f64aa9f0fb414b9f19e501550ae4c0/wal-000000017 (ops 81-85)
I20260812 06:20:23.979246  9110 log.cc:1079] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/78f64aa9f0fb414b9f19e501550ae4c0/wal-000000018 (ops 86-90)
I20260812 06:20:23.979303  9110 log.cc:1079] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/78f64aa9f0fb414b9f19e501550ae4c0/wal-000000019 (ops 91-94)
I20260812 06:20:23.979372  9110 log.cc:1079] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/78f64aa9f0fb414b9f19e501550ae4c0/wal-000000020 (ops 95-99)
I20260812 06:20:23.979391  9110 log.cc:1079] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/78f64aa9f0fb414b9f19e501550ae4c0/wal-000000021 (ops 100-104)
I20260812 06:20:23.979446  9110 log.cc:1079] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/78f64aa9f0fb414b9f19e501550ae4c0/wal-000000022 (ops 105-109)
I20260812 06:20:23.979485  9110 log.cc:1079] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/78f64aa9f0fb414b9f19e501550ae4c0/wal-000000023 (ops 110-114)
I20260812 06:20:23.979537  9110 log.cc:1079] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/78f64aa9f0fb414b9f19e501550ae4c0/wal-000000024 (ops 115-119)
I20260812 06:20:23.979575  9110 log.cc:1079] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/78f64aa9f0fb414b9f19e501550ae4c0/wal-000000025 (ops 120-124)
I20260812 06:20:24.006795  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: LogGCOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.028s	user 0.004s	sys 0.023s Metrics: {}
I20260812 06:20:24.007165  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling UndoDeltaBlockGCOp(78f64aa9f0fb414b9f19e501550ae4c0): 462 bytes on disk
I20260812 06:20:24.007570  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: UndoDeltaBlockGCOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4}
I20260812 06:20:24.008055  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=3.181125
I20260812 06:20:24.033084  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.025s	user 0.009s	sys 0.011s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4978,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:24.033579  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=2.188937
I20260812 06:20:24.043515  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3834,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:24.044121  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling MajorDeltaCompactionOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=1.000000
I20260812 06:20:24.269810  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: MajorDeltaCompactionOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.225s	user 0.152s	sys 0.064s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877327,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1008,"lbm_read_time_us":15683,"lbm_reads_lt_1ms":674,"lbm_write_time_us":41656,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1664,"thread_start_us":189,"threads_started":1,"update_count":3000}
I20260812 06:20:24.270548  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=14.095187
I20260812 06:20:24.340811  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.070s	user 0.051s	sys 0.015s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":26186,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:24.341395  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=2.188937
I20260812 06:20:24.354605  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.013s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5164,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.355052  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling MajorDeltaCompactionOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=1.000000
I20260812 06:20:24.534616  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: MajorDeltaCompactionOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.179s	user 0.115s	sys 0.063s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1553,"lbm_read_time_us":13961,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33311,"lbm_writes_lt_1ms":543,"mutex_wait_us":368,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5888,"update_count":2500}
I20260812 06:20:24.538116  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=11.118625
I20260812 06:20:24.584591  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.046s	user 0.023s	sys 0.020s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":21163,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:24.585223  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=2.188937
I20260812 06:20:24.596258  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4271,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:24.597007  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling MajorDeltaCompactionOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=1.000000
I20260812 06:20:24.745996  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: MajorDeltaCompactionOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.149s	user 0.118s	sys 0.027s 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":564,"lbm_read_time_us":9027,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26944,"lbm_writes_lt_1ms":443,"mutex_wait_us":24,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":71808,"update_count":2000}
I20260812 06:20:24.746594  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=10.126437
I20260812 06:20:24.791090  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.044s	user 0.023s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17504,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:24.791587  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=2.188937
I20260812 06:20:24.802786  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4463,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.803217  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling MajorDeltaCompactionOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=1.000000
I20260812 06:20:24.922012  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: MajorDeltaCompactionOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.119s	user 0.098s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":282,"lbm_read_time_us":9099,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23199,"lbm_writes_lt_1ms":443,"mutex_wait_us":25,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8960,"update_count":2000}
I20260812 06:20:24.922708  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=10.126437
I20260812 06:20:24.961880  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.039s	user 0.022s	sys 0.014s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16212,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:24.962491  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling MajorDeltaCompactionOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=1.000000
I20260812 06:20:25.074663  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: MajorDeltaCompactionOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.112s	user 0.093s	sys 0.019s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569746,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":484,"lbm_read_time_us":8057,"lbm_reads_lt_1ms":363,"lbm_write_time_us":20695,"lbm_writes_lt_1ms":343,"mutex_wait_us":88,"peak_mem_usage":38262756,"reinsert_count":0,"update_count":1500}
I20260812 06:20:25.075295  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=10.126437
I20260812 06:20:25.120442  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.045s	user 0.021s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16116,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:25.121037  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=2.188937
I20260812 06:20:25.132138  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4138,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.132956  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling MajorDeltaCompactionOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=1.000000
I20260812 06:20:25.274060  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: MajorDeltaCompactionOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.141s	user 0.101s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":332,"lbm_read_time_us":9096,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28964,"lbm_writes_lt_1ms":443,"mutex_wait_us":69,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10368,"update_count":2000}
I20260812 06:20:25.274852  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=10.126437
I20260812 06:20:25.320866  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.046s	user 0.012s	sys 0.024s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":16442,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:25.321331  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=2.188937
I20260812 06:20:25.332443  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4126,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.333038  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling MajorDeltaCompactionOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=1.000000
I20260812 06:20:25.480964  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: MajorDeltaCompactionOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.148s	user 0.113s	sys 0.031s 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":731,"lbm_read_time_us":10489,"lbm_reads_lt_1ms":472,"lbm_write_time_us":30362,"lbm_writes_lt_1ms":443,"mutex_wait_us":28,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":17408,"update_count":2000}
I20260812 06:20:25.481909  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=10.126437
I20260812 06:20:25.528393  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.046s	user 0.027s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20130,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:25.528993  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=2.188937
I20260812 06:20:25.541654  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4461,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.542171  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling FlushMRSOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=1.000000
I20260812 06:20:25.574952  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: FlushMRSOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.033s	user 0.031s	sys 0.001s Metrics: {"bytes_written":1234475,"cfile_init":1,"dirs.queue_time_us":63,"dirs.run_cpu_time_us":226,"dirs.run_wall_time_us":1439,"drs_written":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1719,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:25.575665  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling LogGCOp(78f64aa9f0fb414b9f19e501550ae4c0): free 121006622 bytes of WAL
I20260812 06:20:25.575906  9110 log_reader.cc:385] T 78f64aa9f0fb414b9f19e501550ae4c0: removed 12 log segments from log reader
I20260812 06:20:25.575958  9110 log.cc:1079] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/78f64aa9f0fb414b9f19e501550ae4c0/wal-000000026 (ops 125-129)
I20260812 06:20:25.576022  9110 log.cc:1079] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/78f64aa9f0fb414b9f19e501550ae4c0/wal-000000027 (ops 130-134)
I20260812 06:20:25.576077  9110 log.cc:1079] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/78f64aa9f0fb414b9f19e501550ae4c0/wal-000000028 (ops 135-139)
I20260812 06:20:25.576125  9110 log.cc:1079] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/78f64aa9f0fb414b9f19e501550ae4c0/wal-000000029 (ops 140-144)
I20260812 06:20:25.576174  9110 log.cc:1079] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/78f64aa9f0fb414b9f19e501550ae4c0/wal-000000030 (ops 145-149)
I20260812 06:20:25.576218  9110 log.cc:1079] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/78f64aa9f0fb414b9f19e501550ae4c0/wal-000000031 (ops 150-154)
I20260812 06:20:25.576258  9110 log.cc:1079] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/78f64aa9f0fb414b9f19e501550ae4c0/wal-000000032 (ops 155-158)
I20260812 06:20:25.576305  9110 log.cc:1079] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/78f64aa9f0fb414b9f19e501550ae4c0/wal-000000033 (ops 159-163)
I20260812 06:20:25.576349  9110 log.cc:1079] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/78f64aa9f0fb414b9f19e501550ae4c0/wal-000000034 (ops 164-168)
I20260812 06:20:25.576393  9110 log.cc:1079] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/78f64aa9f0fb414b9f19e501550ae4c0/wal-000000035 (ops 169-173)
I20260812 06:20:25.576436  9110 log.cc:1079] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/78f64aa9f0fb414b9f19e501550ae4c0/wal-000000036 (ops 174-178)
I20260812 06:20:25.576480  9110 log.cc:1079] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/78f64aa9f0fb414b9f19e501550ae4c0/wal-000000037 (ops 179-183)
I20260812 06:20:25.605823  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: LogGCOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.030s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:20:25.606405  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling UndoDeltaBlockGCOp(78f64aa9f0fb414b9f19e501550ae4c0): 472 bytes on disk
I20260812 06:20:25.606835  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: UndoDeltaBlockGCOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:20:25.607579  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=5.165500
I20260812 06:20:25.630858  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.023s	user 0.015s	sys 0.008s Metrics: {"bytes_written":7097423,"delete_count":0,"lbm_write_time_us":9541,"lbm_writes_lt_1ms":176,"reinsert_count":0,"update_count":865}
I20260812 06:20:25.631505  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling LogGCOp(78f64aa9f0fb414b9f19e501550ae4c0): free 12018006 bytes of WAL
I20260812 06:20:25.631840  9110 log_reader.cc:385] T 78f64aa9f0fb414b9f19e501550ae4c0: removed 1 log segments from log reader
I20260812 06:20:25.631901  9110 log.cc:1079] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/78f64aa9f0fb414b9f19e501550ae4c0/wal-000000038 (ops 184-188)
I20260812 06:20:25.635275  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: LogGCOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.003s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:20:25.635829  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling MajorDeltaCompactionOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=1.000000
I20260812 06:20:25.818905  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: MajorDeltaCompactionOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.183s	user 0.121s	sys 0.053s Metrics: {"cfile_cache_miss":606,"cfile_cache_miss_bytes":27769566,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":507,"lbm_read_time_us":13341,"lbm_reads_lt_1ms":642,"lbm_write_time_us":36223,"lbm_writes_lt_1ms":616,"mutex_wait_us":37,"peak_mem_usage":71313375,"reinsert_count":0,"spinlock_wait_cycles":7808,"thread_start_us":82,"threads_started":1,"update_count":2865}
I20260812 06:20:25.820013  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=15.087375
I20260812 06:20:25.875509  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.055s	user 0.023s	sys 0.028s Metrics: {"bytes_written":17517556,"delete_count":0,"lbm_write_time_us":23939,"lbm_writes_lt_1ms":430,"reinsert_count":0,"update_count":2135}
I20260812 06:20:25.875962  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=2.188937
I20260812 06:20:25.887398  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: FlushDeltaMemStoresOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4200,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.888015  9215 maintenance_manager.cc:419] P 36f1622a576b42249b44dd508b5ac6ba: Scheduling MajorDeltaCompactionOp(78f64aa9f0fb414b9f19e501550ae4c0): perf score=1.000000
I20260812 06:20:25.919006  8944 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.132s	user 1.839s	sys 0.162s
I20260812 06:20:25.977128  8944 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.057s	user 0.003s	sys 0.000s
I20260812 06:20:25.977910  8944 tablet_server.cc:179] TabletServer@127.8.188.1:0 shutting down...
I20260812 06:20:26.025731  9110 maintenance_manager.cc:643] P 36f1622a576b42249b44dd508b5ac6ba: MajorDeltaCompactionOp(78f64aa9f0fb414b9f19e501550ae4c0) complete. Timing: real 0.137s	user 0.097s	sys 0.040s Metrics: {"cfile_cache_miss":559,"cfile_cache_miss_bytes":25882343,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":375,"lbm_read_time_us":12278,"lbm_reads_lt_1ms":595,"lbm_write_time_us":28376,"lbm_writes_lt_1ms":570,"mutex_wait_us":72,"peak_mem_usage":66304613,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2635}
I20260812 06:20:26.026551  8944 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:26.026942  8944 tablet_replica.cc:333] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba: stopping tablet replica
I20260812 06:20:26.027288  8944 raft_consensus.cc:2243] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:26.039637  8944 raft_consensus.cc:2272] T 78f64aa9f0fb414b9f19e501550ae4c0 P 36f1622a576b42249b44dd508b5ac6ba [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:26.057070  8944 tablet_server.cc:196] TabletServer@127.8.188.1:0 shutdown complete.
I20260812 06:20:26.074587  8944 master.cc:562] Master@127.8.188.62:44689 shutting down...
I20260812 06:20:26.078905  8944 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 42db54eae18c4f73873dd2a42e92d669 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:26.079078  8944 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 42db54eae18c4f73873dd2a42e92d669 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:26.079149  8944 tablet_replica.cc:333] T 00000000000000000000000000000000 P 42db54eae18c4f73873dd2a42e92d669: stopping tablet replica
I20260812 06:20:26.092132  8944 master.cc:584] Master@127.8.188.62:44689 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5659 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:20:26.191463  8944 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.8.188.62:41785
I20260812 06:20:26.191870  8944 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:26.193799  9267 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:26.193840  9268 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:20:26.193936  9272 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:26.194017  8944 server_base.cc:1061] running on GCE node
I20260812 06:20:26.194378  8944 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:26.194447  8944 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:26.194494  8944 hybrid_clock.cc:648] HybridClock initialized: now 1786515626194492 us; error 0 us; skew 500 ppm
I20260812 06:20:26.195672  8944 webserver.cc:533] Webserver started at http://127.8.188.62:46587/ using document root <none> and password file <none>
I20260812 06:20:26.195871  8944 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:26.195936  8944 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:26.196030  8944 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:26.196468  8944 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620521417-8944-0/minicluster-data/master-0-root/instance:
uuid: "73561ee1c59e4ad7b3ecbc49e5420485"
format_stamp: "Formatted at 2026-08-12 06:20:26 on dist-test-slave-7nm7"
I20260812 06:20:26.198057  8944 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:20:26.199209  9280 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:26.199527  8944 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:26.199625  8944 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620521417-8944-0/minicluster-data/master-0-root
uuid: "73561ee1c59e4ad7b3ecbc49e5420485"
format_stamp: "Formatted at 2026-08-12 06:20:26 on dist-test-slave-7nm7"
I20260812 06:20:26.199725  8944 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620521417-8944-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620521417-8944-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620521417-8944-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:26.207667  8944 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:26.208082  8944 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:26.212746  8944 rpc_server.cc:307] RPC server started. Bound to: 127.8.188.62:41785
I20260812 06:20:26.215606  9379 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.8.188.62:41785 every 8 connection(s)
I20260812 06:20:26.219981  9380 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:26.223991  9380 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 73561ee1c59e4ad7b3ecbc49e5420485: Bootstrap starting.
I20260812 06:20:26.224818  9380 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 73561ee1c59e4ad7b3ecbc49e5420485: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:26.225894  9380 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 73561ee1c59e4ad7b3ecbc49e5420485: No bootstrap required, opened a new log
I20260812 06:20:26.226334  9380 raft_consensus.cc:359] T 00000000000000000000000000000000 P 73561ee1c59e4ad7b3ecbc49e5420485 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "73561ee1c59e4ad7b3ecbc49e5420485" member_type: VOTER }
I20260812 06:20:26.226449  9380 raft_consensus.cc:385] T 00000000000000000000000000000000 P 73561ee1c59e4ad7b3ecbc49e5420485 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:26.226475  9380 raft_consensus.cc:740] T 00000000000000000000000000000000 P 73561ee1c59e4ad7b3ecbc49e5420485 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 73561ee1c59e4ad7b3ecbc49e5420485, State: Initialized, Role: FOLLOWER
I20260812 06:20:26.226624  9380 consensus_queue.cc:260] T 00000000000000000000000000000000 P 73561ee1c59e4ad7b3ecbc49e5420485 [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: "73561ee1c59e4ad7b3ecbc49e5420485" member_type: VOTER }
I20260812 06:20:26.226707  9380 raft_consensus.cc:399] T 00000000000000000000000000000000 P 73561ee1c59e4ad7b3ecbc49e5420485 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:26.226732  9380 raft_consensus.cc:493] T 00000000000000000000000000000000 P 73561ee1c59e4ad7b3ecbc49e5420485 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:26.226760  9380 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 73561ee1c59e4ad7b3ecbc49e5420485 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:26.227403  9380 raft_consensus.cc:515] T 00000000000000000000000000000000 P 73561ee1c59e4ad7b3ecbc49e5420485 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "73561ee1c59e4ad7b3ecbc49e5420485" member_type: VOTER }
I20260812 06:20:26.227514  9380 leader_election.cc:304] T 00000000000000000000000000000000 P 73561ee1c59e4ad7b3ecbc49e5420485 [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: 73561ee1c59e4ad7b3ecbc49e5420485; no voters: 
I20260812 06:20:26.227675  9380 leader_election.cc:290] T 00000000000000000000000000000000 P 73561ee1c59e4ad7b3ecbc49e5420485 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:26.227825  9386 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 73561ee1c59e4ad7b3ecbc49e5420485 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:26.228190  9386 raft_consensus.cc:697] T 00000000000000000000000000000000 P 73561ee1c59e4ad7b3ecbc49e5420485 [term 1 LEADER]: Becoming Leader. State: Replica: 73561ee1c59e4ad7b3ecbc49e5420485, State: Running, Role: LEADER
I20260812 06:20:26.228304  9380 sys_catalog.cc:565] T 00000000000000000000000000000000 P 73561ee1c59e4ad7b3ecbc49e5420485 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:26.228370  9386 consensus_queue.cc:237] T 00000000000000000000000000000000 P 73561ee1c59e4ad7b3ecbc49e5420485 [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: "73561ee1c59e4ad7b3ecbc49e5420485" member_type: VOTER }
I20260812 06:20:26.228839  9389 sys_catalog.cc:455] T 00000000000000000000000000000000 P 73561ee1c59e4ad7b3ecbc49e5420485 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 73561ee1c59e4ad7b3ecbc49e5420485. Latest consensus state: current_term: 1 leader_uuid: "73561ee1c59e4ad7b3ecbc49e5420485" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "73561ee1c59e4ad7b3ecbc49e5420485" member_type: VOTER } }
I20260812 06:20:26.228819  9387 sys_catalog.cc:455] T 00000000000000000000000000000000 P 73561ee1c59e4ad7b3ecbc49e5420485 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "73561ee1c59e4ad7b3ecbc49e5420485" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "73561ee1c59e4ad7b3ecbc49e5420485" member_type: VOTER } }
I20260812 06:20:26.228929  9389 sys_catalog.cc:458] T 00000000000000000000000000000000 P 73561ee1c59e4ad7b3ecbc49e5420485 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:26.228940  9387 sys_catalog.cc:458] T 00000000000000000000000000000000 P 73561ee1c59e4ad7b3ecbc49e5420485 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:26.229267  9398 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:26.230083  9398 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:26.230475  8944 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:26.231981  9398 catalog_manager.cc:1383] Generated new cluster ID: 3e889fd174b0490da13ec32079622cd1
I20260812 06:20:26.232039  9398 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:26.245497  9398 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:26.246148  9398 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:26.256969  9398 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 73561ee1c59e4ad7b3ecbc49e5420485: Generated new TSK 0
I20260812 06:20:26.257189  9398 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:26.262795  8944 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:26.264797  9423 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:20:26.264797  9426 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:26.264976  9420 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:26.265152  8944 server_base.cc:1061] running on GCE node
I20260812 06:20:26.265305  8944 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:26.265376  8944 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:26.265394  8944 hybrid_clock.cc:648] HybridClock initialized: now 1786515626265394 us; error 0 us; skew 500 ppm
I20260812 06:20:26.266347  8944 webserver.cc:533] Webserver started at http://127.8.188.1:41881/ using document root <none> and password file <none>
I20260812 06:20:26.266534  8944 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:26.266619  8944 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:26.266696  8944 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:26.267093  8944 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620521417-8944-0/minicluster-data/ts-0-root/instance:
uuid: "0577230f0c924281b104bd537d556c66"
format_stamp: "Formatted at 2026-08-12 06:20:26 on dist-test-slave-7nm7"
I20260812 06:20:26.268636  8944 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:26.269675  9433 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:26.269954  8944 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:26.270062  8944 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620521417-8944-0/minicluster-data/ts-0-root
uuid: "0577230f0c924281b104bd537d556c66"
format_stamp: "Formatted at 2026-08-12 06:20:26 on dist-test-slave-7nm7"
I20260812 06:20:26.270134  8944 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620521417-8944-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620521417-8944-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620521417-8944-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:26.283972  8944 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:26.284344  8944 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:26.284674  8944 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:26.285171  8944 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:26.285230  8944 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:26.285281  8944 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:26.285331  8944 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:26.289690  8944 rpc_server.cc:307] RPC server started. Bound to: 127.8.188.1:40103
I20260812 06:20:26.291172  9555 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.8.188.1:40103 every 8 connection(s)
I20260812 06:20:26.299142  9557 heartbeater.cc:344] Connected to a master server at 127.8.188.62:41785
I20260812 06:20:26.299268  9557 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:26.299528  9557 heartbeater.cc:507] Master 127.8.188.62:41785 requested a full tablet report, sending...
I20260812 06:20:26.300264  9309 ts_manager.cc:194] Registered new tserver with Master: 0577230f0c924281b104bd537d556c66 (127.8.188.1:40103)
I20260812 06:20:26.300917  8944 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.01020053s
I20260812 06:20:26.301173  9309 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:39164
I20260812 06:20:26.309167  9309 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:39178:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:20:26.318059  9477 tablet_service.cc:1511] Processing CreateTablet for tablet b41e33d5e9f043219751a0562d020a5b (DEFAULT_TABLE table=heavy-update-compaction-test [id=7658cc0164d24a52a954b181725bd62b]), partition=
I20260812 06:20:26.318406  9477 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet b41e33d5e9f043219751a0562d020a5b. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:26.320453  9574 tablet_bootstrap.cc:492] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66: Bootstrap starting.
I20260812 06:20:26.321388  9574 tablet_bootstrap.cc:654] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:26.322641  9574 tablet_bootstrap.cc:492] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66: No bootstrap required, opened a new log
I20260812 06:20:26.322746  9574 ts_tablet_manager.cc:1403] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:26.323220  9574 raft_consensus.cc:359] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0577230f0c924281b104bd537d556c66" member_type: VOTER last_known_addr { host: "127.8.188.1" port: 40103 } }
I20260812 06:20:26.323308  9574 raft_consensus.cc:385] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:26.323330  9574 raft_consensus.cc:740] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 0577230f0c924281b104bd537d556c66, State: Initialized, Role: FOLLOWER
I20260812 06:20:26.323518  9574 consensus_queue.cc:260] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66 [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: "0577230f0c924281b104bd537d556c66" member_type: VOTER last_known_addr { host: "127.8.188.1" port: 40103 } }
I20260812 06:20:26.323621  9574 raft_consensus.cc:399] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:26.323647  9574 raft_consensus.cc:493] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:26.323727  9574 raft_consensus.cc:3060] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:26.324779  9574 raft_consensus.cc:515] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0577230f0c924281b104bd537d556c66" member_type: VOTER last_known_addr { host: "127.8.188.1" port: 40103 } }
I20260812 06:20:26.324900  9574 leader_election.cc:304] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66 [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: 0577230f0c924281b104bd537d556c66; no voters: 
I20260812 06:20:26.325143  9574 leader_election.cc:290] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:26.325294  9576 raft_consensus.cc:2804] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:26.325510  9574 ts_tablet_manager.cc:1434] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:20:26.325527  9557 heartbeater.cc:499] Master 127.8.188.62:41785 was elected leader, sending a full tablet report...
I20260812 06:20:26.325590  9576 raft_consensus.cc:697] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66 [term 1 LEADER]: Becoming Leader. State: Replica: 0577230f0c924281b104bd537d556c66, State: Running, Role: LEADER
I20260812 06:20:26.325759  9576 consensus_queue.cc:237] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66 [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: "0577230f0c924281b104bd537d556c66" member_type: VOTER last_known_addr { host: "127.8.188.1" port: 40103 } }
I20260812 06:20:26.327271  9309 catalog_manager.cc:5719] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66 reported cstate change: term changed from 0 to 1, leader changed from <none> to 0577230f0c924281b104bd537d556c66 (127.8.188.1). New cstate: current_term: 1 leader_uuid: "0577230f0c924281b104bd537d556c66" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0577230f0c924281b104bd537d556c66" member_type: VOTER last_known_addr { host: "127.8.188.1" port: 40103 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:26.388868  8944 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.054s	user 0.018s	sys 0.005s
I20260812 06:20:26.541692  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling FlushMRSOp(b41e33d5e9f043219751a0562d020a5b): perf score=19.054940
I20260812 06:20:26.713408  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: FlushMRSOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.171s	user 0.128s	sys 0.040s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":215,"dirs.run_wall_time_us":954,"drs_written":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4,"lbm_write_time_us":47559,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:20:26.714439  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling LogGCOp(b41e33d5e9f043219751a0562d020a5b): free 20743880 bytes of WAL
I20260812 06:20:26.714737  9438 log_reader.cc:385] T b41e33d5e9f043219751a0562d020a5b: removed 2 log segments from log reader
I20260812 06:20:26.714807  9438 log.cc:1079] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/b41e33d5e9f043219751a0562d020a5b/wal-000000001 (ops 1-6)
I20260812 06:20:26.714864  9438 log.cc:1079] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/b41e33d5e9f043219751a0562d020a5b/wal-000000002 (ops 7-11)
I20260812 06:20:26.720121  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: LogGCOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.005s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:20:26.720516  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling UndoDeltaBlockGCOp(b41e33d5e9f043219751a0562d020a5b): 16411397 bytes on disk
I20260812 06:20:26.720952  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: UndoDeltaBlockGCOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4}
I20260812 06:20:26.721460  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b): perf score=2.188937
I20260812 06:20:26.736615  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.015s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6058,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.737035  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling MajorDeltaCompactionOp(b41e33d5e9f043219751a0562d020a5b): perf score=1.000000
I20260812 06:20:26.898324  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: MajorDeltaCompactionOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.161s	user 0.093s	sys 0.056s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":696,"lbm_read_time_us":12165,"lbm_reads_lt_1ms":464,"lbm_write_time_us":28302,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"thread_start_us":342,"threads_started":5,"update_count":2000}
I20260812 06:20:26.898912  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b): perf score=14.095187
I20260812 06:20:26.966168  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.067s	user 0.037s	sys 0.011s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":23171,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:26.966679  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b): perf score=2.188937
I20260812 06:20:26.978521  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4767,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.978979  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling MajorDeltaCompactionOp(b41e33d5e9f043219751a0562d020a5b): perf score=1.000000
I20260812 06:20:27.192682  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: MajorDeltaCompactionOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.214s	user 0.141s	sys 0.071s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":511,"lbm_read_time_us":16647,"lbm_reads_lt_1ms":572,"lbm_write_time_us":37796,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:20:27.193267  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b): perf score=14.095187
I20260812 06:20:27.272888  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.079s	user 0.037s	sys 0.038s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":32300,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:27.273510  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b): perf score=2.188937
I20260812 06:20:27.290907  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.017s	user 0.017s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6802,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.291463  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling MajorDeltaCompactionOp(b41e33d5e9f043219751a0562d020a5b): perf score=1.000000
I20260812 06:20:27.504447  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: MajorDeltaCompactionOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.213s	user 0.130s	sys 0.071s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":761,"lbm_read_time_us":16237,"lbm_reads_lt_1ms":568,"lbm_write_time_us":33740,"lbm_writes_lt_1ms":543,"mutex_wait_us":33,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":84992,"update_count":2500}
I20260812 06:20:27.505111  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b): perf score=18.063937
I20260812 06:20:27.582634  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.077s	user 0.038s	sys 0.039s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":30612,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:27.583252  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b): perf score=2.188937
I20260812 06:20:27.593958  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4215,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.594408  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling MajorDeltaCompactionOp(b41e33d5e9f043219751a0562d020a5b): perf score=1.000000
I20260812 06:20:27.813726  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: MajorDeltaCompactionOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.219s	user 0.126s	sys 0.093s 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":225,"lbm_read_time_us":15922,"lbm_reads_lt_1ms":672,"lbm_write_time_us":39244,"lbm_writes_lt_1ms":643,"mutex_wait_us":47,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":15232,"update_count":3000}
I20260812 06:20:27.814568  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b): perf score=14.095187
I20260812 06:20:27.874768  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.060s	user 0.026s	sys 0.021s Metrics: {"bytes_written":16409907,"delete_count":0,"lbm_write_time_us":20170,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:27.875370  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b): perf score=2.188937
I20260812 06:20:27.888024  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.012s	user 0.002s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4804,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.888554  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling MajorDeltaCompactionOp(b41e33d5e9f043219751a0562d020a5b): perf score=1.000000
I20260812 06:20:28.081842  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: MajorDeltaCompactionOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.193s	user 0.133s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774694,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":380,"lbm_read_time_us":14428,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33669,"lbm_writes_lt_1ms":543,"mutex_wait_us":46,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15488,"update_count":2500}
I20260812 06:20:28.082407  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b): perf score=14.095187
I20260812 06:20:28.150919  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.068s	user 0.027s	sys 0.040s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":26758,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:28.151584  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b): perf score=2.188937
I20260812 06:20:28.164448  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.013s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4909,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.165014  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling FlushMRSOp(b41e33d5e9f043219751a0562d020a5b): perf score=1.000000
I20260812 06:20:28.210005  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: FlushMRSOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.045s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":57,"dirs.run_cpu_time_us":287,"dirs.run_wall_time_us":1239,"drs_written":1,"lbm_read_time_us":94,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1896,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:28.210704  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling UndoDeltaBlockGCOp(b41e33d5e9f043219751a0562d020a5b): 483 bytes on disk
I20260812 06:20:28.211421  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: UndoDeltaBlockGCOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":77,"lbm_reads_lt_1ms":4}
I20260812 06:20:28.212019  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b): perf score=3.181125
I20260812 06:20:28.226816  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.015s	user 0.001s	sys 0.012s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":5351,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:28.227279  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling LogGCOp(b41e33d5e9f043219751a0562d020a5b): free 120553376 bytes of WAL
I20260812 06:20:28.227504  9438 log_reader.cc:385] T b41e33d5e9f043219751a0562d020a5b: removed 12 log segments from log reader
I20260812 06:20:28.227548  9438 log.cc:1079] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/b41e33d5e9f043219751a0562d020a5b/wal-000000003 (ops 12-16)
I20260812 06:20:28.227602  9438 log.cc:1079] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/b41e33d5e9f043219751a0562d020a5b/wal-000000004 (ops 17-21)
I20260812 06:20:28.227656  9438 log.cc:1079] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/b41e33d5e9f043219751a0562d020a5b/wal-000000005 (ops 22-26)
I20260812 06:20:28.227725  9438 log.cc:1079] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/b41e33d5e9f043219751a0562d020a5b/wal-000000006 (ops 27-31)
I20260812 06:20:28.227771  9438 log.cc:1079] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/b41e33d5e9f043219751a0562d020a5b/wal-000000007 (ops 32-36)
I20260812 06:20:28.227815  9438 log.cc:1079] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/b41e33d5e9f043219751a0562d020a5b/wal-000000008 (ops 37-41)
I20260812 06:20:28.227861  9438 log.cc:1079] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/b41e33d5e9f043219751a0562d020a5b/wal-000000009 (ops 42-46)
I20260812 06:20:28.227900  9438 log.cc:1079] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/b41e33d5e9f043219751a0562d020a5b/wal-000000010 (ops 47-50)
I20260812 06:20:28.227942  9438 log.cc:1079] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/b41e33d5e9f043219751a0562d020a5b/wal-000000011 (ops 51-55)
I20260812 06:20:28.227986  9438 log.cc:1079] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/b41e33d5e9f043219751a0562d020a5b/wal-000000012 (ops 56-60)
I20260812 06:20:28.228029  9438 log.cc:1079] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/b41e33d5e9f043219751a0562d020a5b/wal-000000013 (ops 61-64)
I20260812 06:20:28.228080  9438 log.cc:1079] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/b41e33d5e9f043219751a0562d020a5b/wal-000000014 (ops 65-69)
I20260812 06:20:28.257824  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: LogGCOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.030s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:20:28.258376  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b): perf score=2.188937
I20260812 06:20:28.275211  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.017s	user 0.009s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4568,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.275755  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling LogGCOp(b41e33d5e9f043219751a0562d020a5b): free 12017932 bytes of WAL
I20260812 06:20:28.276001  9438 log_reader.cc:385] T b41e33d5e9f043219751a0562d020a5b: removed 1 log segments from log reader
I20260812 06:20:28.276046  9438 log.cc:1079] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/b41e33d5e9f043219751a0562d020a5b/wal-000000015 (ops 70-74)
I20260812 06:20:28.278729  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: LogGCOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.003s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:20:28.279022  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b): perf score=2.188937
I20260812 06:20:28.291512  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.012s	user 0.005s	sys 0.006s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4645,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:28.291968  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling MajorDeltaCompactionOp(b41e33d5e9f043219751a0562d020a5b): perf score=1.000000
I20260812 06:20:28.574741  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: MajorDeltaCompactionOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.283s	user 0.201s	sys 0.077s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37082268,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":592,"dirs.run_cpu_time_us":449,"dirs.run_wall_time_us":4082,"lbm_read_time_us":21551,"lbm_reads_lt_1ms":875,"lbm_write_time_us":56788,"lbm_writes_lt_1ms":843,"mutex_wait_us":65,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":11392,"thread_start_us":105,"threads_started":1,"update_count":4000}
I20260812 06:20:28.575631  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b): perf score=19.056125
I20260812 06:20:28.644865  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.069s	user 0.030s	sys 0.036s Metrics: {"bytes_written":21619968,"delete_count":0,"lbm_write_time_us":31953,"lbm_writes_lt_1ms":530,"reinsert_count":0,"update_count":2635}
I20260812 06:20:28.645318  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b): perf score=5.165500
I20260812 06:20:28.672729  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.027s	user 0.015s	sys 0.008s Metrics: {"bytes_written":7097429,"delete_count":0,"lbm_write_time_us":10912,"lbm_writes_lt_1ms":176,"reinsert_count":0,"update_count":865}
I20260812 06:20:28.673173  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling MajorDeltaCompactionOp(b41e33d5e9f043219751a0562d020a5b): perf score=1.000000
I20260812 06:20:28.875137  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: MajorDeltaCompactionOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.202s	user 0.168s	sys 0.032s Metrics: {"cfile_cache_miss":732,"cfile_cache_miss_bytes":32979519,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":263,"lbm_read_time_us":15867,"lbm_reads_lt_1ms":764,"lbm_write_time_us":44405,"lbm_writes_lt_1ms":743,"mutex_wait_us":3,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":6784,"update_count":3500}
I20260812 06:20:28.875718  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b): perf score=18.063937
I20260812 06:20:28.943912  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.068s	user 0.050s	sys 0.016s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":29726,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:28.944397  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b): perf score=2.188937
I20260812 06:20:28.966881  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.022s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5596,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.967374  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b): perf score=2.188937
I20260812 06:20:28.978670  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.011s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4543,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.979436  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling MajorDeltaCompactionOp(b41e33d5e9f043219751a0562d020a5b): perf score=1.000000
I20260812 06:20:29.192342  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: MajorDeltaCompactionOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.213s	user 0.165s	sys 0.043s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32979635,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":303,"lbm_read_time_us":17282,"lbm_reads_lt_1ms":773,"lbm_write_time_us":45509,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":14080,"update_count":3500}
I20260812 06:20:29.193084  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b): perf score=15.087375
I20260812 06:20:29.245250  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.052s	user 0.025s	sys 0.023s Metrics: {"bytes_written":16820144,"delete_count":0,"lbm_write_time_us":23490,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:20:29.246121  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b): perf score=2.188937
I20260812 06:20:29.257587  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4361,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:29.258014  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling MajorDeltaCompactionOp(b41e33d5e9f043219751a0562d020a5b): perf score=1.000000
I20260812 06:20:29.431478  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: MajorDeltaCompactionOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.173s	user 0.136s	sys 0.014s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774677,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":329,"lbm_read_time_us":11727,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30230,"lbm_writes_lt_1ms":543,"mutex_wait_us":51,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10368,"update_count":2500}
I20260812 06:20:29.432183  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b): perf score=14.095187
I20260812 06:20:29.487581  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.055s	user 0.041s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":26849,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:29.488047  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b): perf score=2.188937
I20260812 06:20:29.500080  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4271,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.501444  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling MajorDeltaCompactionOp(b41e33d5e9f043219751a0562d020a5b): perf score=1.000000
I20260812 06:20:29.700594  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: MajorDeltaCompactionOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.199s	user 0.099s	sys 0.099s 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":807,"lbm_read_time_us":12832,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34044,"lbm_writes_lt_1ms":543,"mutex_wait_us":369,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":2500}
I20260812 06:20:29.701313  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b): perf score=14.095187
I20260812 06:20:29.751530  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.050s	user 0.039s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22293,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:29.752103  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling FlushMRSOp(b41e33d5e9f043219751a0562d020a5b): perf score=1.000000
I20260812 06:20:29.792665  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: FlushMRSOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.040s	user 0.024s	sys 0.004s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":79,"dirs.run_cpu_time_us":241,"dirs.run_wall_time_us":1154,"drs_written":1,"lbm_read_time_us":77,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2341,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31,"spinlock_wait_cycles":15104}
I20260812 06:20:29.793619  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling UndoDeltaBlockGCOp(b41e33d5e9f043219751a0562d020a5b): 482 bytes on disk
I20260812 06:20:29.794070  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: UndoDeltaBlockGCOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4}
I20260812 06:20:29.794607  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b): perf score=3.181125
I20260812 06:20:29.816277  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.021s	user 0.011s	sys 0.008s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":8450,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:29.816759  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling LogGCOp(b41e33d5e9f043219751a0562d020a5b): free 121006462 bytes of WAL
I20260812 06:20:29.817000  9438 log_reader.cc:385] T b41e33d5e9f043219751a0562d020a5b: removed 12 log segments from log reader
I20260812 06:20:29.817049  9438 log.cc:1079] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/b41e33d5e9f043219751a0562d020a5b/wal-000000016 (ops 75-79)
I20260812 06:20:29.817082  9438 log.cc:1079] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/b41e33d5e9f043219751a0562d020a5b/wal-000000017 (ops 80-84)
I20260812 06:20:29.817134  9438 log.cc:1079] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/b41e33d5e9f043219751a0562d020a5b/wal-000000018 (ops 85-89)
I20260812 06:20:29.817183  9438 log.cc:1079] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/b41e33d5e9f043219751a0562d020a5b/wal-000000019 (ops 90-94)
I20260812 06:20:29.817235  9438 log.cc:1079] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/b41e33d5e9f043219751a0562d020a5b/wal-000000020 (ops 95-99)
I20260812 06:20:29.817291  9438 log.cc:1079] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/b41e33d5e9f043219751a0562d020a5b/wal-000000021 (ops 100-104)
I20260812 06:20:29.817314  9438 log.cc:1079] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/b41e33d5e9f043219751a0562d020a5b/wal-000000022 (ops 105-108)
I20260812 06:20:29.817375  9438 log.cc:1079] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/b41e33d5e9f043219751a0562d020a5b/wal-000000023 (ops 109-113)
I20260812 06:20:29.817425  9438 log.cc:1079] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/b41e33d5e9f043219751a0562d020a5b/wal-000000024 (ops 114-118)
I20260812 06:20:29.817472  9438 log.cc:1079] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/b41e33d5e9f043219751a0562d020a5b/wal-000000025 (ops 119-123)
I20260812 06:20:29.817519  9438 log.cc:1079] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/b41e33d5e9f043219751a0562d020a5b/wal-000000026 (ops 124-128)
I20260812 06:20:29.817561  9438 log.cc:1079] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/b41e33d5e9f043219751a0562d020a5b/wal-000000027 (ops 129-133)
I20260812 06:20:29.846266  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: LogGCOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.029s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:20:29.846712  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b): perf score=2.188937
I20260812 06:20:29.864549  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.018s	user 0.004s	sys 0.006s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4553,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:29.865028  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b): perf score=2.188937
I20260812 06:20:29.876886  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4779,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.877355  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling MajorDeltaCompactionOp(b41e33d5e9f043219751a0562d020a5b): perf score=1.000000
I20260812 06:20:30.115819  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: MajorDeltaCompactionOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.238s	user 0.150s	sys 0.088s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979737,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":194,"lbm_read_time_us":20332,"lbm_reads_lt_1ms":774,"lbm_write_time_us":42434,"lbm_writes_lt_1ms":743,"mutex_wait_us":50,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":100096,"thread_start_us":78,"threads_started":1,"update_count":3500}
I20260812 06:20:30.116485  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b): perf score=18.063937
I20260812 06:20:30.171412  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.055s	user 0.033s	sys 0.020s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":24681,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:30.171939  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b): perf score=2.188937
I20260812 06:20:30.188158  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.016s	user 0.009s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6483,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:30.188730  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling MajorDeltaCompactionOp(b41e33d5e9f043219751a0562d020a5b): perf score=1.000000
I20260812 06:20:30.373474  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: MajorDeltaCompactionOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.185s	user 0.136s	sys 0.048s 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":205,"lbm_read_time_us":13811,"lbm_reads_lt_1ms":664,"lbm_write_time_us":42074,"lbm_writes_lt_1ms":643,"mutex_wait_us":91,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4096,"update_count":3000}
I20260812 06:20:30.374176  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b): perf score=14.095187
I20260812 06:20:30.432266  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.056s	user 0.022s	sys 0.032s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25941,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:30.432818  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b): perf score=2.188937
I20260812 06:20:30.454099  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.021s	user 0.000s	sys 0.015s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7181,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:30.454622  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling MajorDeltaCompactionOp(b41e33d5e9f043219751a0562d020a5b): perf score=1.000000
I20260812 06:20:30.603785  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: MajorDeltaCompactionOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.149s	user 0.125s	sys 0.019s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":208,"lbm_read_time_us":11739,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29250,"lbm_writes_lt_1ms":543,"mutex_wait_us":66,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:30.604633  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b): perf score=14.095187
I20260812 06:20:30.657845  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.053s	user 0.035s	sys 0.013s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24304,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":26880,"update_count":2000}
I20260812 06:20:30.658674  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b): perf score=3.181125
I20260812 06:20:30.686983  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.028s	user 0.011s	sys 0.005s Metrics: {"bytes_written":4348804,"delete_count":0,"lbm_write_time_us":7050,"lbm_writes_lt_1ms":109,"reinsert_count":0,"update_count":530}
I20260812 06:20:30.687510  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b): perf score=2.188937
I20260812 06:20:30.699029  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":3856509,"delete_count":0,"lbm_write_time_us":4587,"lbm_writes_lt_1ms":97,"reinsert_count":0,"update_count":470}
I20260812 06:20:30.699867  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling MajorDeltaCompactionOp(b41e33d5e9f043219751a0562d020a5b): perf score=1.000000
I20260812 06:20:30.884698  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: MajorDeltaCompactionOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.185s	user 0.141s	sys 0.043s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877214,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":208,"lbm_read_time_us":16436,"lbm_reads_lt_1ms":673,"lbm_write_time_us":35170,"lbm_writes_lt_1ms":643,"mutex_wait_us":37,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":8064,"update_count":3000}
I20260812 06:20:30.885332  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b): perf score=15.087375
I20260812 06:20:30.943755  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.058s	user 0.038s	sys 0.016s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":24779,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:20:30.944254  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b): perf score=2.188937
I20260812 06:20:30.956218  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.012s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4184710,"delete_count":0,"lbm_write_time_us":5021,"lbm_writes_lt_1ms":105,"reinsert_count":0,"update_count":510}
I20260812 06:20:30.956667  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b): perf score=2.188937
I20260812 06:20:30.968904  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3610355,"delete_count":0,"lbm_write_time_us":4379,"lbm_writes_lt_1ms":91,"reinsert_count":0,"update_count":440}
I20260812 06:20:30.969496  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling MajorDeltaCompactionOp(b41e33d5e9f043219751a0562d020a5b): perf score=1.000000
I20260812 06:20:31.151979  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: MajorDeltaCompactionOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.182s	user 0.138s	sys 0.043s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877208,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1263,"lbm_read_time_us":15080,"lbm_reads_lt_1ms":673,"lbm_write_time_us":38399,"lbm_writes_lt_1ms":643,"mutex_wait_us":370,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":14592,"update_count":3000}
I20260812 06:20:31.152631  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b): perf score=14.095187
I20260812 06:20:31.207386  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.055s	user 0.034s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25287,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:31.207942  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b): perf score=2.188937
I20260812 06:20:31.223964  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.016s	user 0.009s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6544,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:31.224418  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling FlushMRSOp(b41e33d5e9f043219751a0562d020a5b): perf score=1.000000
I20260812 06:20:31.258313  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: FlushMRSOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.034s	user 0.032s	sys 0.001s Metrics: {"bytes_written":1234477,"cfile_init":1,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":267,"dirs.run_wall_time_us":1606,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1577,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:31.259243  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling LogGCOp(b41e33d5e9f043219751a0562d020a5b): free 124710524 bytes of WAL
I20260812 06:20:31.259523  9438 log_reader.cc:385] T b41e33d5e9f043219751a0562d020a5b: removed 12 log segments from log reader
I20260812 06:20:31.259609  9438 log.cc:1079] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/b41e33d5e9f043219751a0562d020a5b/wal-000000028 (ops 134-138)
I20260812 06:20:31.259686  9438 log.cc:1079] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/b41e33d5e9f043219751a0562d020a5b/wal-000000029 (ops 139-143)
I20260812 06:20:31.259740  9438 log.cc:1079] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/b41e33d5e9f043219751a0562d020a5b/wal-000000030 (ops 144-148)
I20260812 06:20:31.259780  9438 log.cc:1079] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/b41e33d5e9f043219751a0562d020a5b/wal-000000031 (ops 149-153)
I20260812 06:20:31.259815  9438 log.cc:1079] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/b41e33d5e9f043219751a0562d020a5b/wal-000000032 (ops 154-158)
I20260812 06:20:31.259853  9438 log.cc:1079] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/b41e33d5e9f043219751a0562d020a5b/wal-000000033 (ops 159-163)
I20260812 06:20:31.259888  9438 log.cc:1079] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/b41e33d5e9f043219751a0562d020a5b/wal-000000034 (ops 164-168)
I20260812 06:20:31.259925  9438 log.cc:1079] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/b41e33d5e9f043219751a0562d020a5b/wal-000000035 (ops 169-173)
I20260812 06:20:31.259963  9438 log.cc:1079] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/b41e33d5e9f043219751a0562d020a5b/wal-000000036 (ops 174-178)
I20260812 06:20:31.260003  9438 log.cc:1079] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/b41e33d5e9f043219751a0562d020a5b/wal-000000037 (ops 179-183)
I20260812 06:20:31.260056  9438 log.cc:1079] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/b41e33d5e9f043219751a0562d020a5b/wal-000000038 (ops 184-188)
I20260812 06:20:31.260093  9438 log.cc:1079] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66: Deleting log segment in path: /tmp/dist-test-task9kQBI1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620521417-8944-0/minicluster-data/ts-0-root/wals/b41e33d5e9f043219751a0562d020a5b/wal-000000039 (ops 189-193)
I20260812 06:20:31.291410  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: LogGCOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.032s	user 0.000s	sys 0.031s Metrics: {}
I20260812 06:20:31.291982  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling UndoDeltaBlockGCOp(b41e33d5e9f043219751a0562d020a5b): 473 bytes on disk
I20260812 06:20:31.292443  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: UndoDeltaBlockGCOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4}
I20260812 06:20:31.292966  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b): perf score=4.173312
I20260812 06:20:31.309139  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.016s	user 0.006s	sys 0.007s Metrics: {"bytes_written":5333393,"delete_count":0,"lbm_write_time_us":6547,"lbm_writes_lt_1ms":133,"reinsert_count":0,"update_count":650}
I20260812 06:20:31.309687  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b): perf score=1.196750
I20260812 06:20:31.322844  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.013s	user 0.012s	sys 0.000s Metrics: {"bytes_written":2871905,"delete_count":0,"lbm_write_time_us":4766,"lbm_writes_lt_1ms":73,"reinsert_count":0,"update_count":350}
I20260812 06:20:31.323562  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling MajorDeltaCompactionOp(b41e33d5e9f043219751a0562d020a5b): perf score=1.000000
I20260812 06:20:31.423378  8944 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.034s	user 1.871s	sys 0.113s
I20260812 06:20:31.507104  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: MajorDeltaCompactionOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.183s	user 0.155s	sys 0.028s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979724,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":797,"lbm_read_time_us":17672,"lbm_reads_lt_1ms":770,"lbm_write_time_us":37370,"lbm_writes_lt_1ms":743,"mutex_wait_us":107,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":9216,"thread_start_us":82,"threads_started":1,"update_count":3500}
I20260812 06:20:31.507911  9558 maintenance_manager.cc:419] P 0577230f0c924281b104bd537d556c66: Scheduling FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b): perf score=6.157687
I20260812 06:20:31.518040  8944 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.094s	user 0.001s	sys 0.000s
I20260812 06:20:31.518612  8944 tablet_server.cc:179] TabletServer@127.8.188.1:0 shutting down...
I20260812 06:20:31.534662  9438 maintenance_manager.cc:643] P 0577230f0c924281b104bd537d556c66: FlushDeltaMemStoresOp(b41e33d5e9f043219751a0562d020a5b) complete. Timing: real 0.027s	user 0.018s	sys 0.008s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":11414,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:20:31.535699  8944 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:31.535934  8944 tablet_replica.cc:333] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66: stopping tablet replica
I20260812 06:20:31.536078  8944 raft_consensus.cc:2243] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:31.536249  8944 raft_consensus.cc:2272] T b41e33d5e9f043219751a0562d020a5b P 0577230f0c924281b104bd537d556c66 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:31.549963  8944 tablet_server.cc:196] TabletServer@127.8.188.1:0 shutdown complete.
I20260812 06:20:31.565004  8944 master.cc:562] Master@127.8.188.62:41785 shutting down...
I20260812 06:20:31.568300  8944 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 73561ee1c59e4ad7b3ecbc49e5420485 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:31.568496  8944 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 73561ee1c59e4ad7b3ecbc49e5420485 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:31.568581  8944 tablet_replica.cc:333] T 00000000000000000000000000000000 P 73561ee1c59e4ad7b3ecbc49e5420485: stopping tablet replica
I20260812 06:20:31.580976  8944 master.cc:584] Master@127.8.188.62:41785 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5482 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11142 ms total)

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