[==========] 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:18:28.438577  3841 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.3.192.126:38705
I20260812 06:18:28.439558  3841 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:18:28.440122  3841 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:18:28.446353  3841 server_base.cc:1061] running on GCE node
W20260812 06:18:28.446396  3852 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:18:28.446557  3850 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:18:28.446779  3855 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:18:28.447237  3841 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:28.447346  3841 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:18:28.447381  3841 hybrid_clock.cc:648] HybridClock initialized: now 1786515508447379 us; error 0 us; skew 500 ppm
I20260812 06:18:28.449112  3841 webserver.cc:533] Webserver started at http://127.3.192.126:34761/ using document root <none> and password file <none>
I20260812 06:18:28.449623  3841 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:28.449678  3841 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:28.449864  3841 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:28.451472  3841 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515508427787-3841-0/minicluster-data/master-0-root/instance:
uuid: "734731ee2c834d8c81945890b6e36fff"
format_stamp: "Formatted at 2026-08-12 06:18:28 on dist-test-slave-xt4k"
I20260812 06:18:28.454912  3841 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.001s	sys 0.004s
I20260812 06:18:28.457079  3867 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:18:28.458179  3841 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:28.458292  3841 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515508427787-3841-0/minicluster-data/master-0-root
uuid: "734731ee2c834d8c81945890b6e36fff"
format_stamp: "Formatted at 2026-08-12 06:18:28 on dist-test-slave-xt4k"
I20260812 06:18:28.458398  3841 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515508427787-3841-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515508427787-3841-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515508427787-3841-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:18:28.477237  3841 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:28.477876  3841 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:18:28.478035  3841 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:28.485864  3978 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.3.192.126:38705 every 8 connection(s)
I20260812 06:18:28.485879  3841 rpc_server.cc:307] RPC server started. Bound to: 127.3.192.126:38705
I20260812 06:18:28.488103  3979 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:18:28.493490  3979 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 734731ee2c834d8c81945890b6e36fff: Bootstrap starting.
I20260812 06:18:28.495771  3979 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 734731ee2c834d8c81945890b6e36fff: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:28.496673  3979 log.cc:826] T 00000000000000000000000000000000 P 734731ee2c834d8c81945890b6e36fff: Log is configured to *not* fsync() on all Append() calls
I20260812 06:18:28.498396  3979 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 734731ee2c834d8c81945890b6e36fff: No bootstrap required, opened a new log
I20260812 06:18:28.501207  3979 raft_consensus.cc:359] T 00000000000000000000000000000000 P 734731ee2c834d8c81945890b6e36fff [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "734731ee2c834d8c81945890b6e36fff" member_type: VOTER }
I20260812 06:18:28.501368  3979 raft_consensus.cc:385] T 00000000000000000000000000000000 P 734731ee2c834d8c81945890b6e36fff [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:28.501413  3979 raft_consensus.cc:740] T 00000000000000000000000000000000 P 734731ee2c834d8c81945890b6e36fff [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 734731ee2c834d8c81945890b6e36fff, State: Initialized, Role: FOLLOWER
I20260812 06:18:28.501991  3979 consensus_queue.cc:260] T 00000000000000000000000000000000 P 734731ee2c834d8c81945890b6e36fff [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: "734731ee2c834d8c81945890b6e36fff" member_type: VOTER }
I20260812 06:18:28.502133  3979 raft_consensus.cc:399] T 00000000000000000000000000000000 P 734731ee2c834d8c81945890b6e36fff [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:28.502193  3979 raft_consensus.cc:493] T 00000000000000000000000000000000 P 734731ee2c834d8c81945890b6e36fff [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:28.502311  3979 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 734731ee2c834d8c81945890b6e36fff [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:28.503080  3979 raft_consensus.cc:515] T 00000000000000000000000000000000 P 734731ee2c834d8c81945890b6e36fff [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "734731ee2c834d8c81945890b6e36fff" member_type: VOTER }
I20260812 06:18:28.503502  3979 leader_election.cc:304] T 00000000000000000000000000000000 P 734731ee2c834d8c81945890b6e36fff [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: 734731ee2c834d8c81945890b6e36fff; no voters: 
I20260812 06:18:28.503806  3979 leader_election.cc:290] T 00000000000000000000000000000000 P 734731ee2c834d8c81945890b6e36fff [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:28.503942  3988 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 734731ee2c834d8c81945890b6e36fff [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:28.504160  3988 raft_consensus.cc:697] T 00000000000000000000000000000000 P 734731ee2c834d8c81945890b6e36fff [term 1 LEADER]: Becoming Leader. State: Replica: 734731ee2c834d8c81945890b6e36fff, State: Running, Role: LEADER
I20260812 06:18:28.504581  3988 consensus_queue.cc:237] T 00000000000000000000000000000000 P 734731ee2c834d8c81945890b6e36fff [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: "734731ee2c834d8c81945890b6e36fff" member_type: VOTER }
I20260812 06:18:28.504743  3979 sys_catalog.cc:565] T 00000000000000000000000000000000 P 734731ee2c834d8c81945890b6e36fff [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:28.506369  3989 sys_catalog.cc:455] T 00000000000000000000000000000000 P 734731ee2c834d8c81945890b6e36fff [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "734731ee2c834d8c81945890b6e36fff" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "734731ee2c834d8c81945890b6e36fff" member_type: VOTER } }
I20260812 06:18:28.506356  3990 sys_catalog.cc:455] T 00000000000000000000000000000000 P 734731ee2c834d8c81945890b6e36fff [sys.catalog]: SysCatalogTable state changed. Reason: New leader 734731ee2c834d8c81945890b6e36fff. Latest consensus state: current_term: 1 leader_uuid: "734731ee2c834d8c81945890b6e36fff" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "734731ee2c834d8c81945890b6e36fff" member_type: VOTER } }
I20260812 06:18:28.506486  3989 sys_catalog.cc:458] T 00000000000000000000000000000000 P 734731ee2c834d8c81945890b6e36fff [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:28.506486  3990 sys_catalog.cc:458] T 00000000000000000000000000000000 P 734731ee2c834d8c81945890b6e36fff [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:28.506851  4017 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:28.506939  3841 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:28.509087  4017 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:28.513166  4017 catalog_manager.cc:1383] Generated new cluster ID: 055c0844dedf4edb89da83e24f4b06b6
I20260812 06:18:28.513227  4017 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:28.534684  4017 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:28.535843  4017 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:28.557832  4017 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 734731ee2c834d8c81945890b6e36fff: Generated new TSK 0
I20260812 06:18:28.558454  4017 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:28.571727  3841 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:28.574505  4027 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:18:28.574506  4029 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:18:28.574571  4032 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:18:28.574754  3841 server_base.cc:1061] running on GCE node
I20260812 06:18:28.574985  3841 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:28.575040  3841 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:18:28.575080  3841 hybrid_clock.cc:648] HybridClock initialized: now 1786515508575080 us; error 0 us; skew 500 ppm
I20260812 06:18:28.575953  3841 webserver.cc:533] Webserver started at http://127.3.192.65:33663/ using document root <none> and password file <none>
I20260812 06:18:28.576110  3841 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:28.576164  3841 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:28.576232  3841 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:28.576715  3841 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515508427787-3841-0/minicluster-data/ts-0-root/instance:
uuid: "36c3ffc9dcb04c35bbb76b92f703a7f2"
format_stamp: "Formatted at 2026-08-12 06:18:28 on dist-test-slave-xt4k"
I20260812 06:18:28.578413  3841 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:28.579399  4040 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:18:28.579687  3841 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:28.579766  3841 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515508427787-3841-0/minicluster-data/ts-0-root
uuid: "36c3ffc9dcb04c35bbb76b92f703a7f2"
format_stamp: "Formatted at 2026-08-12 06:18:28 on dist-test-slave-xt4k"
I20260812 06:18:28.579833  3841 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515508427787-3841-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515508427787-3841-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515508427787-3841-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:18:28.589226  3841 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:28.589727  3841 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:28.590226  3841 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:28.591207  3841 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:28.591272  3841 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:28.591326  3841 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:28.591356  3841 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:28.598031  3841 rpc_server.cc:307] RPC server started. Bound to: 127.3.192.65:40689
I20260812 06:18:28.598084  4162 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.3.192.65:40689 every 8 connection(s)
I20260812 06:18:28.608098  4163 heartbeater.cc:344] Connected to a master server at 127.3.192.126:38705
I20260812 06:18:28.608357  4163 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:28.608780  4163 heartbeater.cc:507] Master 127.3.192.126:38705 requested a full tablet report, sending...
I20260812 06:18:28.610217  3905 ts_manager.cc:194] Registered new tserver with Master: 36c3ffc9dcb04c35bbb76b92f703a7f2 (127.3.192.65:40689)
I20260812 06:18:28.610932  3841 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012233327s
I20260812 06:18:28.611390  3905 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:55218
I20260812 06:18:28.620545  3905 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:55220:
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:18:28.634684  4091 tablet_service.cc:1511] Processing CreateTablet for tablet 5de138f6d1934c948c403a519953edd4 (DEFAULT_TABLE table=heavy-update-compaction-test [id=73ea694bc6f24b5588bf175ba3cdc285]), partition=
I20260812 06:18:28.635139  4091 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 5de138f6d1934c948c403a519953edd4. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:28.637565  4181 tablet_bootstrap.cc:492] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2: Bootstrap starting.
I20260812 06:18:28.638832  4181 tablet_bootstrap.cc:654] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:28.640141  4181 tablet_bootstrap.cc:492] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2: No bootstrap required, opened a new log
I20260812 06:18:28.640261  4181 ts_tablet_manager.cc:1403] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:18:28.640805  4181 raft_consensus.cc:359] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "36c3ffc9dcb04c35bbb76b92f703a7f2" member_type: VOTER last_known_addr { host: "127.3.192.65" port: 40689 } }
I20260812 06:18:28.640933  4181 raft_consensus.cc:385] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:28.640969  4181 raft_consensus.cc:740] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 36c3ffc9dcb04c35bbb76b92f703a7f2, State: Initialized, Role: FOLLOWER
I20260812 06:18:28.641103  4181 consensus_queue.cc:260] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2 [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: "36c3ffc9dcb04c35bbb76b92f703a7f2" member_type: VOTER last_known_addr { host: "127.3.192.65" port: 40689 } }
I20260812 06:18:28.641238  4181 raft_consensus.cc:399] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:28.641289  4181 raft_consensus.cc:493] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:28.641366  4181 raft_consensus.cc:3060] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:28.642432  4181 raft_consensus.cc:515] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "36c3ffc9dcb04c35bbb76b92f703a7f2" member_type: VOTER last_known_addr { host: "127.3.192.65" port: 40689 } }
I20260812 06:18:28.642603  4181 leader_election.cc:304] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2 [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: 36c3ffc9dcb04c35bbb76b92f703a7f2; no voters: 
I20260812 06:18:28.642920  4181 leader_election.cc:290] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:28.643139  4188 raft_consensus.cc:2804] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:28.643301  4181 ts_tablet_manager.cc:1434] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:18:28.643493  4163 heartbeater.cc:499] Master 127.3.192.126:38705 was elected leader, sending a full tablet report...
I20260812 06:18:28.643772  4188 raft_consensus.cc:697] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2 [term 1 LEADER]: Becoming Leader. State: Replica: 36c3ffc9dcb04c35bbb76b92f703a7f2, State: Running, Role: LEADER
I20260812 06:18:28.643911  4188 consensus_queue.cc:237] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2 [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: "36c3ffc9dcb04c35bbb76b92f703a7f2" member_type: VOTER last_known_addr { host: "127.3.192.65" port: 40689 } }
I20260812 06:18:28.646660  3905 catalog_manager.cc:5719] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2 reported cstate change: term changed from 0 to 1, leader changed from <none> to 36c3ffc9dcb04c35bbb76b92f703a7f2 (127.3.192.65). New cstate: current_term: 1 leader_uuid: "36c3ffc9dcb04c35bbb76b92f703a7f2" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "36c3ffc9dcb04c35bbb76b92f703a7f2" member_type: VOTER last_known_addr { host: "127.3.192.65" port: 40689 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:28.709271  3841 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.054s	user 0.017s	sys 0.008s
I20260812 06:18:28.849164  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling FlushMRSOp(5de138f6d1934c948c403a519953edd4): perf score=19.054940
I20260812 06:18:29.007278  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: FlushMRSOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.158s	user 0.130s	sys 0.017s Metrics: {"bytes_written":12717735,"cfile_init":1,"compiler_manager_pool.queue_time_us":212,"delete_count":0,"dirs.queue_time_us":41,"dirs.run_cpu_time_us":216,"dirs.run_wall_time_us":805,"drs_written":1,"lbm_read_time_us":77,"lbm_reads_lt_1ms":4,"lbm_write_time_us":34575,"lbm_writes_lt_1ms":767,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":122,"threads_started":1,"update_count":1550}
I20260812 06:18:29.008558  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling LogGCOp(5de138f6d1934c948c403a519953edd4): free 20743880 bytes of WAL
I20260812 06:18:29.008874  4049 log_reader.cc:385] T 5de138f6d1934c948c403a519953edd4: removed 2 log segments from log reader
I20260812 06:18:29.008955  4049 log.cc:1079] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/5de138f6d1934c948c403a519953edd4/wal-000000001 (ops 1-6)
I20260812 06:18:29.009064  4049 log.cc:1079] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/5de138f6d1934c948c403a519953edd4/wal-000000002 (ops 7-11)
I20260812 06:18:29.014153  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: LogGCOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.005s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:18:29.014695  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling UndoDeltaBlockGCOp(5de138f6d1934c948c403a519953edd4): 16411395 bytes on disk
I20260812 06:18:29.015404  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: UndoDeltaBlockGCOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":80,"lbm_reads_lt_1ms":4}
I20260812 06:18:29.015887  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4): perf score=2.188937
I20260812 06:18:29.045487  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.029s	user 0.003s	sys 0.016s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5293,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:29.045989  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4): perf score=2.188937
I20260812 06:18:29.058907  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4947,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:29.059374  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling MajorDeltaCompactionOp(5de138f6d1934c948c403a519953edd4): perf score=1.000000
I20260812 06:18:29.216917  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: MajorDeltaCompactionOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.157s	user 0.105s	sys 0.052s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":491,"lbm_read_time_us":10450,"lbm_reads_lt_1ms":569,"lbm_write_time_us":25988,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":313,"threads_started":5,"update_count":2500}
I20260812 06:18:29.217451  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4): perf score=10.126437
I20260812 06:18:29.258468  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.041s	user 0.012s	sys 0.021s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14274,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:29.258942  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4): perf score=2.188937
I20260812 06:18:29.274217  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.015s	user 0.013s	sys 0.000s 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:18:29.274767  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling MajorDeltaCompactionOp(5de138f6d1934c948c403a519953edd4): perf score=1.000000
I20260812 06:18:29.383843  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: MajorDeltaCompactionOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.109s	user 0.080s	sys 0.027s 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":512,"lbm_read_time_us":7625,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20125,"lbm_writes_lt_1ms":443,"mutex_wait_us":294,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12160,"update_count":2000}
I20260812 06:18:29.384317  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4): perf score=10.126437
I20260812 06:18:29.425591  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.041s	user 0.020s	sys 0.009s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":12830,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:29.426059  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4): perf score=2.188937
I20260812 06:18:29.435949  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3698,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:29.436739  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling MajorDeltaCompactionOp(5de138f6d1934c948c403a519953edd4): perf score=1.000000
I20260812 06:18:29.556722  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: MajorDeltaCompactionOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.120s	user 0.083s	sys 0.036s 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":274,"lbm_read_time_us":10096,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21494,"lbm_writes_lt_1ms":443,"mutex_wait_us":34,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13440,"update_count":2000}
I20260812 06:18:29.557186  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4): perf score=10.126437
I20260812 06:18:29.605195  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.048s	user 0.015s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15796,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:29.605870  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4): perf score=2.188937
I20260812 06:18:29.616322  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3783,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:29.616904  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling MajorDeltaCompactionOp(5de138f6d1934c948c403a519953edd4): perf score=1.000000
I20260812 06:18:29.743129  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: MajorDeltaCompactionOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.126s	user 0.099s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":623,"lbm_read_time_us":8680,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24031,"lbm_writes_lt_1ms":443,"mutex_wait_us":305,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":30208,"update_count":2000}
I20260812 06:18:29.743618  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4): perf score=10.126437
I20260812 06:18:29.787200  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.043s	user 0.021s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15193,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:29.787874  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4): perf score=2.188937
I20260812 06:18:29.802722  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.015s	user 0.001s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5622,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:29.803256  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling MajorDeltaCompactionOp(5de138f6d1934c948c403a519953edd4): perf score=1.000000
I20260812 06:18:29.947357  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: MajorDeltaCompactionOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.144s	user 0.096s	sys 0.048s 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":811,"lbm_read_time_us":10754,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22916,"lbm_writes_lt_1ms":443,"mutex_wait_us":293,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8064,"update_count":2000}
I20260812 06:18:29.947993  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4): perf score=10.126437
I20260812 06:18:29.987576  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.039s	user 0.023s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14234,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:29.988107  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4): perf score=2.188937
I20260812 06:18:30.003401  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.015s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5606,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:30.003989  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling MajorDeltaCompactionOp(5de138f6d1934c948c403a519953edd4): perf score=1.000000
I20260812 06:18:30.121603  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: MajorDeltaCompactionOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.117s	user 0.100s	sys 0.017s 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":608,"lbm_read_time_us":8783,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22555,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:30.122184  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4): perf score=10.126437
I20260812 06:18:30.163597  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.041s	user 0.019s	sys 0.013s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":15833,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:30.164176  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4): perf score=2.188937
I20260812 06:18:30.174301  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3754,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:30.174866  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling FlushMRSOp(5de138f6d1934c948c403a519953edd4): perf score=1.000000
I20260812 06:18:30.206648  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: FlushMRSOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.032s	user 0.024s	sys 0.004s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":49,"dirs.run_cpu_time_us":238,"dirs.run_wall_time_us":1176,"drs_written":1,"lbm_read_time_us":82,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1526,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:18:30.207528  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling LogGCOp(5de138f6d1934c948c403a519953edd4): free 116849505 bytes of WAL
I20260812 06:18:30.207775  4049 log_reader.cc:385] T 5de138f6d1934c948c403a519953edd4: removed 12 log segments from log reader
I20260812 06:18:30.207825  4049 log.cc:1079] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/5de138f6d1934c948c403a519953edd4/wal-000000003 (ops 12-16)
I20260812 06:18:30.207865  4049 log.cc:1079] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/5de138f6d1934c948c403a519953edd4/wal-000000004 (ops 17-20)
I20260812 06:18:30.207897  4049 log.cc:1079] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/5de138f6d1934c948c403a519953edd4/wal-000000005 (ops 21-25)
I20260812 06:18:30.207927  4049 log.cc:1079] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/5de138f6d1934c948c403a519953edd4/wal-000000006 (ops 26-30)
I20260812 06:18:30.207957  4049 log.cc:1079] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/5de138f6d1934c948c403a519953edd4/wal-000000007 (ops 31-35)
I20260812 06:18:30.207986  4049 log.cc:1079] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/5de138f6d1934c948c403a519953edd4/wal-000000008 (ops 36-40)
I20260812 06:18:30.208016  4049 log.cc:1079] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/5de138f6d1934c948c403a519953edd4/wal-000000009 (ops 41-44)
I20260812 06:18:30.208046  4049 log.cc:1079] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/5de138f6d1934c948c403a519953edd4/wal-000000010 (ops 45-49)
I20260812 06:18:30.208076  4049 log.cc:1079] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/5de138f6d1934c948c403a519953edd4/wal-000000011 (ops 50-54)
I20260812 06:18:30.208105  4049 log.cc:1079] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/5de138f6d1934c948c403a519953edd4/wal-000000012 (ops 55-58)
I20260812 06:18:30.208134  4049 log.cc:1079] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/5de138f6d1934c948c403a519953edd4/wal-000000013 (ops 59-63)
I20260812 06:18:30.208163  4049 log.cc:1079] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/5de138f6d1934c948c403a519953edd4/wal-000000014 (ops 64-68)
I20260812 06:18:30.229313  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: LogGCOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.022s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:18:30.229784  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4): perf score=3.181125
I20260812 06:18:30.250193  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.020s	user 0.009s	sys 0.005s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":6489,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:30.250620  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling UndoDeltaBlockGCOp(5de138f6d1934c948c403a519953edd4): 461 bytes on disk
I20260812 06:18:30.251006  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: UndoDeltaBlockGCOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4}
I20260812 06:18:30.251451  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4): perf score=2.188937
I20260812 06:18:30.260730  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.009s	user 0.001s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3325,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:30.261163  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling MajorDeltaCompactionOp(5de138f6d1934c948c403a519953edd4): perf score=1.000000
I20260812 06:18:30.423843  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: MajorDeltaCompactionOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.163s	user 0.144s	sys 0.012s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877328,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":137,"lbm_read_time_us":11172,"lbm_reads_lt_1ms":674,"lbm_write_time_us":30709,"lbm_writes_lt_1ms":643,"mutex_wait_us":41,"peak_mem_usage":75542472,"reinsert_count":0,"thread_start_us":71,"threads_started":1,"update_count":3000}
I20260812 06:18:30.424360  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4): perf score=14.095187
I20260812 06:18:30.469466  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.045s	user 0.033s	sys 0.005s Metrics: {"bytes_written":16409896,"delete_count":0,"lbm_write_time_us":17259,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:30.470042  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4): perf score=2.188937
I20260812 06:18:30.481870  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4115,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:30.482477  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling MajorDeltaCompactionOp(5de138f6d1934c948c403a519953edd4): perf score=1.000000
I20260812 06:18:30.623117  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: MajorDeltaCompactionOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.140s	user 0.117s	sys 0.023s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":666,"lbm_read_time_us":9536,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28465,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8192,"update_count":2500}
I20260812 06:18:30.623646  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4): perf score=12.110812
I20260812 06:18:30.667550  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.044s	user 0.027s	sys 0.012s Metrics: {"bytes_written":13866411,"delete_count":0,"lbm_write_time_us":18478,"lbm_writes_lt_1ms":341,"reinsert_count":0,"update_count":1690}
I20260812 06:18:30.667994  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4): perf score=1.196750
I20260812 06:18:30.682855  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.015s	user 0.003s	sys 0.003s Metrics: {"bytes_written":2953959,"delete_count":0,"lbm_write_time_us":2538,"lbm_writes_lt_1ms":75,"reinsert_count":0,"update_count":360}
I20260812 06:18:30.683322  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4): perf score=2.188937
I20260812 06:18:30.692127  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.009s	user 0.000s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3225,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:30.692552  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling MajorDeltaCompactionOp(5de138f6d1934c948c403a519953edd4): perf score=1.000000
I20260812 06:18:30.861311  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: MajorDeltaCompactionOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.169s	user 0.117s	sys 0.045s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774775,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":110,"lbm_read_time_us":11934,"lbm_reads_lt_1ms":573,"lbm_write_time_us":28175,"lbm_writes_lt_1ms":543,"mutex_wait_us":53,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15360,"update_count":2500}
I20260812 06:18:30.861788  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4): perf score=14.095187
I20260812 06:18:30.915871  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.054s	user 0.036s	sys 0.008s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":21622,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:30.916386  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4): perf score=2.188937
I20260812 06:18:30.926005  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3607,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:30.926425  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling MajorDeltaCompactionOp(5de138f6d1934c948c403a519953edd4): perf score=1.000000
I20260812 06:18:31.084904  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: MajorDeltaCompactionOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.158s	user 0.124s	sys 0.028s 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":279,"lbm_read_time_us":10905,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26889,"lbm_writes_lt_1ms":543,"mutex_wait_us":68,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:18:31.085489  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4): perf score=14.095187
I20260812 06:18:31.138082  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.052s	user 0.036s	sys 0.011s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":17642,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:31.138749  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4): perf score=2.188937
I20260812 06:18:31.149019  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3761,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:31.149529  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling MajorDeltaCompactionOp(5de138f6d1934c948c403a519953edd4): perf score=1.000000
I20260812 06:18:31.325686  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: MajorDeltaCompactionOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.176s	user 0.097s	sys 0.070s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":120,"lbm_read_time_us":11395,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29056,"lbm_writes_lt_1ms":543,"mutex_wait_us":42,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4224,"update_count":2500}
I20260812 06:18:31.326299  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4): perf score=14.095187
I20260812 06:18:31.385057  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.059s	user 0.033s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22429,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:31.385710  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4): perf score=2.188937
I20260812 06:18:31.400789  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.015s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5702,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:31.401305  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling MajorDeltaCompactionOp(5de138f6d1934c948c403a519953edd4): perf score=1.000000
I20260812 06:18:31.571918  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: MajorDeltaCompactionOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.170s	user 0.115s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":255,"lbm_read_time_us":11599,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25726,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:31.572430  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4): perf score=14.095187
I20260812 06:18:31.621937  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.049s	user 0.039s	sys 0.009s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22293,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:31.622403  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4): perf score=2.188937
I20260812 06:18:31.634009  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4110,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:31.634533  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling FlushMRSOp(5de138f6d1934c948c403a519953edd4): perf score=1.000000
I20260812 06:18:31.669646  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: FlushMRSOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.035s	user 0.018s	sys 0.012s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":79,"dirs.run_cpu_time_us":208,"dirs.run_wall_time_us":1140,"drs_written":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1733,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:31.670483  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling LogGCOp(5de138f6d1934c948c403a519953edd4): free 128867461 bytes of WAL
I20260812 06:18:31.670714  4049 log_reader.cc:385] T 5de138f6d1934c948c403a519953edd4: removed 13 log segments from log reader
I20260812 06:18:31.670763  4049 log.cc:1079] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/5de138f6d1934c948c403a519953edd4/wal-000000015 (ops 69-73)
I20260812 06:18:31.670789  4049 log.cc:1079] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/5de138f6d1934c948c403a519953edd4/wal-000000016 (ops 74-78)
I20260812 06:18:31.670805  4049 log.cc:1079] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/5de138f6d1934c948c403a519953edd4/wal-000000017 (ops 79-82)
I20260812 06:18:31.670835  4049 log.cc:1079] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/5de138f6d1934c948c403a519953edd4/wal-000000018 (ops 83-87)
I20260812 06:18:31.670864  4049 log.cc:1079] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/5de138f6d1934c948c403a519953edd4/wal-000000019 (ops 88-92)
I20260812 06:18:31.670897  4049 log.cc:1079] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/5de138f6d1934c948c403a519953edd4/wal-000000020 (ops 93-96)
I20260812 06:18:31.670923  4049 log.cc:1079] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/5de138f6d1934c948c403a519953edd4/wal-000000021 (ops 97-101)
I20260812 06:18:31.670954  4049 log.cc:1079] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/5de138f6d1934c948c403a519953edd4/wal-000000022 (ops 102-106)
I20260812 06:18:31.670984  4049 log.cc:1079] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/5de138f6d1934c948c403a519953edd4/wal-000000023 (ops 107-111)
I20260812 06:18:31.671016  4049 log.cc:1079] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/5de138f6d1934c948c403a519953edd4/wal-000000024 (ops 112-116)
I20260812 06:18:31.671048  4049 log.cc:1079] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/5de138f6d1934c948c403a519953edd4/wal-000000025 (ops 117-120)
I20260812 06:18:31.671079  4049 log.cc:1079] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/5de138f6d1934c948c403a519953edd4/wal-000000026 (ops 121-125)
I20260812 06:18:31.671110  4049 log.cc:1079] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/5de138f6d1934c948c403a519953edd4/wal-000000027 (ops 126-130)
I20260812 06:18:31.693082  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: LogGCOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.022s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:18:31.693542  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4): perf score=3.181125
I20260812 06:18:31.711949  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.018s	user 0.001s	sys 0.009s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4226,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:31.712453  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4): perf score=2.188937
I20260812 06:18:31.725526  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.013s	user 0.006s	sys 0.006s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4755,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:31.726069  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling UndoDeltaBlockGCOp(5de138f6d1934c948c403a519953edd4): 493 bytes on disk
I20260812 06:18:31.726644  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: UndoDeltaBlockGCOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":80,"lbm_reads_lt_1ms":4}
I20260812 06:18:31.727221  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling MajorDeltaCompactionOp(5de138f6d1934c948c403a519953edd4): perf score=1.000000
I20260812 06:18:31.959151  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: MajorDeltaCompactionOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.232s	user 0.153s	sys 0.073s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979736,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":3347,"lbm_read_time_us":14898,"lbm_reads_lt_1ms":774,"lbm_write_time_us":38896,"lbm_writes_lt_1ms":743,"mutex_wait_us":3017,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":3072,"thread_start_us":79,"threads_started":1,"update_count":3500}
I20260812 06:18:31.959714  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4): perf score=17.071750
I20260812 06:18:32.018857  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.059s	user 0.023s	sys 0.031s Metrics: {"bytes_written":18830324,"delete_count":0,"lbm_write_time_us":26300,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":461,"reinsert_count":0,"update_count":2295}
I20260812 06:18:32.019289  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4): perf score=4.173312
I20260812 06:18:32.033706  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.014s	user 0.008s	sys 0.005s Metrics: {"bytes_written":5784660,"delete_count":0,"lbm_write_time_us":5396,"lbm_writes_lt_1ms":144,"reinsert_count":0,"update_count":705}
I20260812 06:18:32.034154  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling MajorDeltaCompactionOp(5de138f6d1934c948c403a519953edd4): perf score=1.000000
I20260812 06:18:32.220098  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: MajorDeltaCompactionOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.186s	user 0.122s	sys 0.060s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877106,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":618,"lbm_read_time_us":12180,"lbm_reads_lt_1ms":664,"lbm_write_time_us":29929,"lbm_writes_lt_1ms":643,"mutex_wait_us":324,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":36352,"update_count":3000}
I20260812 06:18:32.220795  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4): perf score=16.079562
I20260812 06:18:32.285840  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.065s	user 0.017s	sys 0.033s Metrics: {"bytes_written":18297008,"delete_count":0,"lbm_write_time_us":22813,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":448,"reinsert_count":0,"update_count":2230}
I20260812 06:18:32.286301  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4): perf score=5.165500
I20260812 06:18:32.304029  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.018s	user 0.007s	sys 0.008s Metrics: {"bytes_written":6317969,"delete_count":0,"lbm_write_time_us":6885,"lbm_writes_lt_1ms":157,"reinsert_count":0,"update_count":770}
I20260812 06:18:32.304587  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling MajorDeltaCompactionOp(5de138f6d1934c948c403a519953edd4): perf score=1.000000
I20260812 06:18:32.484863  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: MajorDeltaCompactionOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.180s	user 0.133s	sys 0.045s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877099,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":288,"lbm_read_time_us":13193,"lbm_reads_lt_1ms":664,"lbm_write_time_us":28787,"lbm_writes_lt_1ms":643,"mutex_wait_us":68,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":49920,"update_count":3000}
I20260812 06:18:32.486284  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4): perf score=16.079562
I20260812 06:18:32.535389  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.049s	user 0.017s	sys 0.028s Metrics: {"bytes_written":17681654,"delete_count":0,"lbm_write_time_us":21612,"lbm_writes_lt_1ms":434,"reinsert_count":0,"update_count":2155}
I20260812 06:18:32.535893  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4): perf score=1.196750
I20260812 06:18:32.555111  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.019s	user 0.007s	sys 0.000s Metrics: {"bytes_written":2830880,"delete_count":0,"lbm_write_time_us":3257,"lbm_writes_lt_1ms":72,"reinsert_count":0,"update_count":345}
I20260812 06:18:32.555583  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4): perf score=2.188937
I20260812 06:18:32.565719  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3831,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:32.566150  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling MajorDeltaCompactionOp(5de138f6d1934c948c403a519953edd4): perf score=1.000000
I20260812 06:18:32.746778  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: MajorDeltaCompactionOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.180s	user 0.113s	sys 0.067s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877192,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":161,"lbm_read_time_us":13030,"lbm_reads_lt_1ms":673,"lbm_write_time_us":29515,"lbm_writes_lt_1ms":643,"mutex_wait_us":39,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":61696,"update_count":3000}
I20260812 06:18:32.747314  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4): perf score=14.095187
I20260812 06:18:32.806130  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.059s	user 0.033s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20365,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:32.806775  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4): perf score=2.188937
I20260812 06:18:32.817390  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3879,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:32.818015  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling MajorDeltaCompactionOp(5de138f6d1934c948c403a519953edd4): perf score=1.000000
I20260812 06:18:32.978849  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: MajorDeltaCompactionOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.161s	user 0.124s	sys 0.037s 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":975,"lbm_read_time_us":11390,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26570,"lbm_writes_lt_1ms":543,"mutex_wait_us":300,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:18:32.979452  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4): perf score=14.095187
I20260812 06:18:33.034309  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.055s	user 0.034s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18339,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:33.034951  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4): perf score=2.188937
I20260812 06:18:33.050042  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5746,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:33.050565  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling FlushMRSOp(5de138f6d1934c948c403a519953edd4): perf score=1.000000
I20260812 06:18:33.089350  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: FlushMRSOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.039s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1234477,"cfile_init":1,"dirs.queue_time_us":58,"dirs.run_cpu_time_us":188,"dirs.run_wall_time_us":1190,"drs_written":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1793,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:18:33.090195  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling LogGCOp(5de138f6d1934c948c403a519953edd4): free 124257473 bytes of WAL
I20260812 06:18:33.090435  4049 log_reader.cc:385] T 5de138f6d1934c948c403a519953edd4: removed 12 log segments from log reader
I20260812 06:18:33.090507  4049 log.cc:1079] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/5de138f6d1934c948c403a519953edd4/wal-000000028 (ops 131-135)
I20260812 06:18:33.090544  4049 log.cc:1079] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/5de138f6d1934c948c403a519953edd4/wal-000000029 (ops 136-140)
I20260812 06:18:33.090577  4049 log.cc:1079] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/5de138f6d1934c948c403a519953edd4/wal-000000030 (ops 141-145)
I20260812 06:18:33.090610  4049 log.cc:1079] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/5de138f6d1934c948c403a519953edd4/wal-000000031 (ops 146-150)
I20260812 06:18:33.090639  4049 log.cc:1079] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/5de138f6d1934c948c403a519953edd4/wal-000000032 (ops 151-155)
I20260812 06:18:33.090670  4049 log.cc:1079] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/5de138f6d1934c948c403a519953edd4/wal-000000033 (ops 156-160)
I20260812 06:18:33.090701  4049 log.cc:1079] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/5de138f6d1934c948c403a519953edd4/wal-000000034 (ops 161-165)
I20260812 06:18:33.090731  4049 log.cc:1079] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/5de138f6d1934c948c403a519953edd4/wal-000000035 (ops 166-170)
I20260812 06:18:33.090761  4049 log.cc:1079] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/5de138f6d1934c948c403a519953edd4/wal-000000036 (ops 171-174)
I20260812 06:18:33.090792  4049 log.cc:1079] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/5de138f6d1934c948c403a519953edd4/wal-000000037 (ops 175-179)
I20260812 06:18:33.090822  4049 log.cc:1079] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/5de138f6d1934c948c403a519953edd4/wal-000000038 (ops 180-184)
I20260812 06:18:33.090853  4049 log.cc:1079] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/5de138f6d1934c948c403a519953edd4/wal-000000039 (ops 185-189)
I20260812 06:18:33.113360  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: LogGCOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.023s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:18:33.113963  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4): perf score=2.188937
I20260812 06:18:33.133762  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.020s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5902,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:33.134267  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4): perf score=2.188937
I20260812 06:18:33.144682  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3844,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:33.145373  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling UndoDeltaBlockGCOp(5de138f6d1934c948c403a519953edd4): 472 bytes on disk
I20260812 06:18:33.145843  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: UndoDeltaBlockGCOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4}
I20260812 06:18:33.146456  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling MajorDeltaCompactionOp(5de138f6d1934c948c403a519953edd4): perf score=1.000000
I20260812 06:18:33.266201  3841 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.557s	user 1.686s	sys 0.145s
I20260812 06:18:33.355723  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: MajorDeltaCompactionOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.209s	user 0.137s	sys 0.071s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979748,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":521,"lbm_read_time_us":13988,"lbm_reads_lt_1ms":770,"lbm_write_time_us":36790,"lbm_writes_lt_1ms":743,"mutex_wait_us":62,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1664,"thread_start_us":74,"threads_started":1,"update_count":3500}
I20260812 06:18:33.356293  4164 maintenance_manager.cc:419] P 36c3ffc9dcb04c35bbb76b92f703a7f2: Scheduling FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4): perf score=10.126437
I20260812 06:18:33.365289  3841 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.098s	user 0.003s	sys 0.000s
I20260812 06:18:33.365854  3841 tablet_server.cc:179] TabletServer@127.3.192.65:0 shutting down...
I20260812 06:18:33.386752  4049 maintenance_manager.cc:643] P 36c3ffc9dcb04c35bbb76b92f703a7f2: FlushDeltaMemStoresOp(5de138f6d1934c948c403a519953edd4) complete. Timing: real 0.030s	user 0.023s	sys 0.005s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13245,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:33.387295  3841 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:33.387679  3841 tablet_replica.cc:333] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2: stopping tablet replica
I20260812 06:18:33.387902  3841 raft_consensus.cc:2243] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:33.388134  3841 raft_consensus.cc:2272] T 5de138f6d1934c948c403a519953edd4 P 36c3ffc9dcb04c35bbb76b92f703a7f2 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:33.404292  3841 tablet_server.cc:196] TabletServer@127.3.192.65:0 shutdown complete.
I20260812 06:18:33.413075  3841 master.cc:562] Master@127.3.192.126:38705 shutting down...
I20260812 06:18:33.416260  3841 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 734731ee2c834d8c81945890b6e36fff [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:33.416441  3841 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 734731ee2c834d8c81945890b6e36fff [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:33.416517  3841 tablet_replica.cc:333] T 00000000000000000000000000000000 P 734731ee2c834d8c81945890b6e36fff: stopping tablet replica
I20260812 06:18:33.428671  3841 master.cc:584] Master@127.3.192.126:38705 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5065 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:33.503332  3841 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.3.192.126:44715
I20260812 06:18:33.503705  3841 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:33.505630  4210 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:18:33.505689  4212 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:18:33.505689  4214 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:18:33.505949  3841 server_base.cc:1061] running on GCE node
I20260812 06:18:33.506096  3841 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:33.506134  3841 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:18:33.506152  3841 hybrid_clock.cc:648] HybridClock initialized: now 1786515513506152 us; error 0 us; skew 500 ppm
I20260812 06:18:33.506919  3841 webserver.cc:533] Webserver started at http://127.3.192.126:45615/ using document root <none> and password file <none>
I20260812 06:18:33.507068  3841 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:33.507117  3841 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:33.507192  3841 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:33.507560  3841 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515508427787-3841-0/minicluster-data/master-0-root/instance:
uuid: "3661292cf58740048e52f10d4c68d90c"
format_stamp: "Formatted at 2026-08-12 06:18:33 on dist-test-slave-xt4k"
I20260812 06:18:33.509037  3841 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:33.509967  4229 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:18:33.510186  3841 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:33.510263  3841 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515508427787-3841-0/minicluster-data/master-0-root
uuid: "3661292cf58740048e52f10d4c68d90c"
format_stamp: "Formatted at 2026-08-12 06:18:33 on dist-test-slave-xt4k"
I20260812 06:18:33.510339  3841 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515508427787-3841-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515508427787-3841-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515508427787-3841-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:18:33.517069  3841 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:33.517372  3841 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:33.521378  3841 rpc_server.cc:307] RPC server started. Bound to: 127.3.192.126:44715
I20260812 06:18:33.532482  4319 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.3.192.126:44715 every 8 connection(s)
I20260812 06:18:33.532958  4320 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:18:33.534752  4320 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 3661292cf58740048e52f10d4c68d90c: Bootstrap starting.
I20260812 06:18:33.535521  4320 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 3661292cf58740048e52f10d4c68d90c: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:33.536794  4320 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 3661292cf58740048e52f10d4c68d90c: No bootstrap required, opened a new log
I20260812 06:18:33.537240  4320 raft_consensus.cc:359] T 00000000000000000000000000000000 P 3661292cf58740048e52f10d4c68d90c [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3661292cf58740048e52f10d4c68d90c" member_type: VOTER }
I20260812 06:18:33.537333  4320 raft_consensus.cc:385] T 00000000000000000000000000000000 P 3661292cf58740048e52f10d4c68d90c [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:33.537365  4320 raft_consensus.cc:740] T 00000000000000000000000000000000 P 3661292cf58740048e52f10d4c68d90c [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 3661292cf58740048e52f10d4c68d90c, State: Initialized, Role: FOLLOWER
I20260812 06:18:33.537508  4320 consensus_queue.cc:260] T 00000000000000000000000000000000 P 3661292cf58740048e52f10d4c68d90c [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: "3661292cf58740048e52f10d4c68d90c" member_type: VOTER }
I20260812 06:18:33.537580  4320 raft_consensus.cc:399] T 00000000000000000000000000000000 P 3661292cf58740048e52f10d4c68d90c [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:33.537618  4320 raft_consensus.cc:493] T 00000000000000000000000000000000 P 3661292cf58740048e52f10d4c68d90c [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:33.537667  4320 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 3661292cf58740048e52f10d4c68d90c [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:33.538388  4320 raft_consensus.cc:515] T 00000000000000000000000000000000 P 3661292cf58740048e52f10d4c68d90c [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3661292cf58740048e52f10d4c68d90c" member_type: VOTER }
I20260812 06:18:33.538529  4320 leader_election.cc:304] T 00000000000000000000000000000000 P 3661292cf58740048e52f10d4c68d90c [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: 3661292cf58740048e52f10d4c68d90c; no voters: 
I20260812 06:18:33.538830  4320 leader_election.cc:290] T 00000000000000000000000000000000 P 3661292cf58740048e52f10d4c68d90c [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:33.538883  4326 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 3661292cf58740048e52f10d4c68d90c [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:33.539064  4326 raft_consensus.cc:697] T 00000000000000000000000000000000 P 3661292cf58740048e52f10d4c68d90c [term 1 LEADER]: Becoming Leader. State: Replica: 3661292cf58740048e52f10d4c68d90c, State: Running, Role: LEADER
I20260812 06:18:33.539256  4326 consensus_queue.cc:237] T 00000000000000000000000000000000 P 3661292cf58740048e52f10d4c68d90c [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: "3661292cf58740048e52f10d4c68d90c" member_type: VOTER }
I20260812 06:18:33.539295  4320 sys_catalog.cc:565] T 00000000000000000000000000000000 P 3661292cf58740048e52f10d4c68d90c [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:33.539677  4328 sys_catalog.cc:455] T 00000000000000000000000000000000 P 3661292cf58740048e52f10d4c68d90c [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "3661292cf58740048e52f10d4c68d90c" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3661292cf58740048e52f10d4c68d90c" member_type: VOTER } }
I20260812 06:18:33.539795  4328 sys_catalog.cc:458] T 00000000000000000000000000000000 P 3661292cf58740048e52f10d4c68d90c [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:33.539697  4329 sys_catalog.cc:455] T 00000000000000000000000000000000 P 3661292cf58740048e52f10d4c68d90c [sys.catalog]: SysCatalogTable state changed. Reason: New leader 3661292cf58740048e52f10d4c68d90c. Latest consensus state: current_term: 1 leader_uuid: "3661292cf58740048e52f10d4c68d90c" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3661292cf58740048e52f10d4c68d90c" member_type: VOTER } }
I20260812 06:18:33.539919  4329 sys_catalog.cc:458] T 00000000000000000000000000000000 P 3661292cf58740048e52f10d4c68d90c [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:33.540287  4335 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:33.541085  4335 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:33.541225  3841 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:33.542891  4335 catalog_manager.cc:1383] Generated new cluster ID: 5794e92dc7084c76831abc29cb6c74e0
I20260812 06:18:33.542944  4335 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:33.556409  4335 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:33.556953  4335 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:33.561717  4335 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 3661292cf58740048e52f10d4c68d90c: Generated new TSK 0
I20260812 06:18:33.561887  4335 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:33.573763  3841 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:33.575621  4356 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:18:33.575748  4354 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:18:33.575778  3841 server_base.cc:1061] running on GCE node
W20260812 06:18:33.575812  4363 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:18:33.576088  3841 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:33.576138  3841 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:18:33.576151  3841 hybrid_clock.cc:648] HybridClock initialized: now 1786515513576152 us; error 0 us; skew 500 ppm
I20260812 06:18:33.577173  3841 webserver.cc:533] Webserver started at http://127.3.192.65:37867/ using document root <none> and password file <none>
I20260812 06:18:33.577354  3841 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:33.577412  3841 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:33.577489  3841 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:33.577867  3841 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515508427787-3841-0/minicluster-data/ts-0-root/instance:
uuid: "bbe3363593bf4084a00970efb79c5732"
format_stamp: "Formatted at 2026-08-12 06:18:33 on dist-test-slave-xt4k"
I20260812 06:18:33.579294  3841 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:18:33.580153  4372 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:18:33.580377  3841 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:18:33.580452  3841 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515508427787-3841-0/minicluster-data/ts-0-root
uuid: "bbe3363593bf4084a00970efb79c5732"
format_stamp: "Formatted at 2026-08-12 06:18:33 on dist-test-slave-xt4k"
I20260812 06:18:33.580529  3841 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515508427787-3841-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515508427787-3841-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515508427787-3841-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:18:33.586395  3841 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:33.586689  3841 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:33.586957  3841 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:33.587384  3841 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:33.587420  3841 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:33.587459  3841 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:33.587488  3841 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:33.591339  3841 rpc_server.cc:307] RPC server started. Bound to: 127.3.192.65:36827
I20260812 06:18:33.592036  4485 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.3.192.65:36827 every 8 connection(s)
I20260812 06:18:33.599433  4486 heartbeater.cc:344] Connected to a master server at 127.3.192.126:44715
I20260812 06:18:33.599551  4486 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:33.599777  4486 heartbeater.cc:507] Master 127.3.192.126:44715 requested a full tablet report, sending...
I20260812 06:18:33.600484  4259 ts_manager.cc:194] Registered new tserver with Master: bbe3363593bf4084a00970efb79c5732 (127.3.192.65:36827)
I20260812 06:18:33.600868  3841 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.008901703s
I20260812 06:18:33.601476  4259 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:34084
I20260812 06:18:33.607904  4259 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:34090:
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:18:33.616418  4418 tablet_service.cc:1511] Processing CreateTablet for tablet cf8c89e6ee6f4ed68ce9f8452c24f747 (DEFAULT_TABLE table=heavy-update-compaction-test [id=3d10e7d66b454a359a681e25c3a50e08]), partition=
I20260812 06:18:33.616704  4418 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet cf8c89e6ee6f4ed68ce9f8452c24f747. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:33.618587  4514 tablet_bootstrap.cc:492] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732: Bootstrap starting.
I20260812 06:18:33.619428  4514 tablet_bootstrap.cc:654] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:33.620549  4514 tablet_bootstrap.cc:492] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732: No bootstrap required, opened a new log
I20260812 06:18:33.620626  4514 ts_tablet_manager.cc:1403] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:33.621026  4514 raft_consensus.cc:359] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bbe3363593bf4084a00970efb79c5732" member_type: VOTER last_known_addr { host: "127.3.192.65" port: 36827 } }
I20260812 06:18:33.621116  4514 raft_consensus.cc:385] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:33.621138  4514 raft_consensus.cc:740] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: bbe3363593bf4084a00970efb79c5732, State: Initialized, Role: FOLLOWER
I20260812 06:18:33.621271  4514 consensus_queue.cc:260] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732 [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: "bbe3363593bf4084a00970efb79c5732" member_type: VOTER last_known_addr { host: "127.3.192.65" port: 36827 } }
I20260812 06:18:33.621356  4514 raft_consensus.cc:399] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:33.621383  4514 raft_consensus.cc:493] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:33.621441  4514 raft_consensus.cc:3060] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:33.622232  4514 raft_consensus.cc:515] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bbe3363593bf4084a00970efb79c5732" member_type: VOTER last_known_addr { host: "127.3.192.65" port: 36827 } }
I20260812 06:18:33.622356  4514 leader_election.cc:304] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732 [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: bbe3363593bf4084a00970efb79c5732; no voters: 
I20260812 06:18:33.622587  4514 leader_election.cc:290] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:33.622809  4517 raft_consensus.cc:2804] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:33.622852  4514 ts_tablet_manager.cc:1434] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:33.622954  4517 raft_consensus.cc:697] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732 [term 1 LEADER]: Becoming Leader. State: Replica: bbe3363593bf4084a00970efb79c5732, State: Running, Role: LEADER
I20260812 06:18:33.622980  4486 heartbeater.cc:499] Master 127.3.192.126:44715 was elected leader, sending a full tablet report...
I20260812 06:18:33.623099  4517 consensus_queue.cc:237] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732 [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: "bbe3363593bf4084a00970efb79c5732" member_type: VOTER last_known_addr { host: "127.3.192.65" port: 36827 } }
I20260812 06:18:33.624605  4259 catalog_manager.cc:5719] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732 reported cstate change: term changed from 0 to 1, leader changed from <none> to bbe3363593bf4084a00970efb79c5732 (127.3.192.65). New cstate: current_term: 1 leader_uuid: "bbe3363593bf4084a00970efb79c5732" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bbe3363593bf4084a00970efb79c5732" member_type: VOTER last_known_addr { host: "127.3.192.65" port: 36827 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:33.681735  3841 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.050s	user 0.010s	sys 0.012s
I20260812 06:18:33.842489  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling FlushMRSOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=23.023690
I20260812 06:18:33.994115  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: FlushMRSOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.151s	user 0.113s	sys 0.036s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":200,"dirs.run_wall_time_us":862,"drs_written":1,"lbm_read_time_us":34,"lbm_reads_lt_1ms":4,"lbm_write_time_us":38639,"lbm_writes_lt_1ms":857,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":1500}
I20260812 06:18:33.994753  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling LogGCOp(cf8c89e6ee6f4ed68ce9f8452c24f747): free 20743880 bytes of WAL
I20260812 06:18:33.994956  4379 log_reader.cc:385] T cf8c89e6ee6f4ed68ce9f8452c24f747: removed 2 log segments from log reader
I20260812 06:18:33.995000  4379 log.cc:1079] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/cf8c89e6ee6f4ed68ce9f8452c24f747/wal-000000001 (ops 1-6)
I20260812 06:18:33.995028  4379 log.cc:1079] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/cf8c89e6ee6f4ed68ce9f8452c24f747/wal-000000002 (ops 7-11)
I20260812 06:18:33.998556  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: LogGCOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.004s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:18:33.998883  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling UndoDeltaBlockGCOp(cf8c89e6ee6f4ed68ce9f8452c24f747): 20513814 bytes on disk
I20260812 06:18:33.999307  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: UndoDeltaBlockGCOp(cf8c89e6ee6f4ed68ce9f8452c24f747) 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:18:33.999702  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=2.188937
I20260812 06:18:34.015167  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.015s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4225,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:34.015774  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling MajorDeltaCompactionOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=1.000000
I20260812 06:18:34.155400  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: MajorDeltaCompactionOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.139s	user 0.082s	sys 0.046s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":608,"lbm_read_time_us":9060,"lbm_reads_lt_1ms":460,"lbm_write_time_us":23358,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"thread_start_us":332,"threads_started":5,"update_count":2000}
I20260812 06:18:34.156140  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=14.095187
I20260812 06:18:34.207013  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.051s	user 0.023s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19899,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:34.207572  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=2.188937
I20260812 06:18:34.218534  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.011s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3789,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:34.219148  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling MajorDeltaCompactionOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=1.000000
I20260812 06:18:34.375759  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: MajorDeltaCompactionOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.156s	user 0.105s	sys 0.050s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":961,"lbm_read_time_us":10388,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29676,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:18:34.376403  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=11.118625
I20260812 06:18:34.417248  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.041s	user 0.027s	sys 0.012s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":14804,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:34.417723  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=2.188937
I20260812 06:18:34.441879  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.023s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3941,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:34.442298  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=2.188937
I20260812 06:18:34.451576  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.009s	user 0.004s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3495,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:34.451968  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling MajorDeltaCompactionOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=1.000000
I20260812 06:18:34.621424  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: MajorDeltaCompactionOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.169s	user 0.110s	sys 0.056s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815796,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":566,"lbm_read_time_us":12169,"lbm_reads_lt_1ms":573,"lbm_write_time_us":28693,"lbm_writes_lt_1ms":543,"mutex_wait_us":34,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1152,"update_count":2500}
I20260812 06:18:34.621948  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=14.095187
I20260812 06:18:34.679906  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.058s	user 0.025s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19685,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:34.680440  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=2.188937
I20260812 06:18:34.690521  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3578,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:34.690989  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling MajorDeltaCompactionOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=1.000000
I20260812 06:18:34.871876  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: MajorDeltaCompactionOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.181s	user 0.116s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":781,"lbm_read_time_us":13238,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30135,"lbm_writes_lt_1ms":543,"mutex_wait_us":20,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8448,"update_count":2500}
I20260812 06:18:34.872383  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=14.095187
I20260812 06:18:34.926271  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.054s	user 0.024s	sys 0.028s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":21643,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:18:34.926928  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=2.188937
I20260812 06:18:34.937024  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3686,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:34.938442  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling MajorDeltaCompactionOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=1.000000
I20260812 06:18:35.116974  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: MajorDeltaCompactionOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.178s	user 0.098s	sys 0.076s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":897,"lbm_read_time_us":11595,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27707,"lbm_writes_lt_1ms":543,"mutex_wait_us":64,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2500}
I20260812 06:18:35.117609  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=14.095187
I20260812 06:18:35.174201  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.056s	user 0.034s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20245,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:35.174867  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=2.188937
I20260812 06:18:35.185401  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.010s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4034,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:35.185964  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling FlushMRSOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=1.000000
I20260812 06:18:35.218258  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: FlushMRSOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.032s	user 0.022s	sys 0.006s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":89,"dirs.run_cpu_time_us":225,"dirs.run_wall_time_us":1296,"drs_written":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1793,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:18:35.219331  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling MajorDeltaCompactionOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=1.000000
I20260812 06:18:35.389569  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: MajorDeltaCompactionOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.170s	user 0.126s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":675,"lbm_read_time_us":12406,"lbm_reads_lt_1ms":564,"lbm_write_time_us":27034,"lbm_writes_lt_1ms":543,"mutex_wait_us":28,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7424,"update_count":2500}
I20260812 06:18:35.390196  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling LogGCOp(cf8c89e6ee6f4ed68ce9f8452c24f747): free 124710290 bytes of WAL
I20260812 06:18:35.390417  4379 log_reader.cc:385] T cf8c89e6ee6f4ed68ce9f8452c24f747: removed 12 log segments from log reader
I20260812 06:18:35.390458  4379 log.cc:1079] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/cf8c89e6ee6f4ed68ce9f8452c24f747/wal-000000003 (ops 12-16)
I20260812 06:18:35.390492  4379 log.cc:1079] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/cf8c89e6ee6f4ed68ce9f8452c24f747/wal-000000004 (ops 17-21)
I20260812 06:18:35.390522  4379 log.cc:1079] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/cf8c89e6ee6f4ed68ce9f8452c24f747/wal-000000005 (ops 22-26)
I20260812 06:18:35.390602  4379 log.cc:1079] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/cf8c89e6ee6f4ed68ce9f8452c24f747/wal-000000006 (ops 27-31)
I20260812 06:18:35.390640  4379 log.cc:1079] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/cf8c89e6ee6f4ed68ce9f8452c24f747/wal-000000007 (ops 32-36)
I20260812 06:18:35.390662  4379 log.cc:1079] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/cf8c89e6ee6f4ed68ce9f8452c24f747/wal-000000008 (ops 37-41)
I20260812 06:18:35.390690  4379 log.cc:1079] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/cf8c89e6ee6f4ed68ce9f8452c24f747/wal-000000009 (ops 42-46)
I20260812 06:18:35.390745  4379 log.cc:1079] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/cf8c89e6ee6f4ed68ce9f8452c24f747/wal-000000010 (ops 47-51)
I20260812 06:18:35.390777  4379 log.cc:1079] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/cf8c89e6ee6f4ed68ce9f8452c24f747/wal-000000011 (ops 52-56)
I20260812 06:18:35.390827  4379 log.cc:1079] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/cf8c89e6ee6f4ed68ce9f8452c24f747/wal-000000012 (ops 57-61)
I20260812 06:18:35.390858  4379 log.cc:1079] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/cf8c89e6ee6f4ed68ce9f8452c24f747/wal-000000013 (ops 62-66)
I20260812 06:18:35.390906  4379 log.cc:1079] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/cf8c89e6ee6f4ed68ce9f8452c24f747/wal-000000014 (ops 67-71)
I20260812 06:18:35.415179  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: LogGCOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.025s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:18:35.415694  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=18.063937
I20260812 06:18:35.481027  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.065s	user 0.042s	sys 0.023s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":24159,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:35.481703  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling UndoDeltaBlockGCOp(cf8c89e6ee6f4ed68ce9f8452c24f747): 462 bytes on disk
I20260812 06:18:35.483166  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: UndoDeltaBlockGCOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":986,"lbm_reads_lt_1ms":4}
I20260812 06:18:35.484206  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=2.188937
I20260812 06:18:35.498283  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5124,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:35.498781  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling MajorDeltaCompactionOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=1.000000
I20260812 06:18:35.689759  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: MajorDeltaCompactionOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.191s	user 0.128s	sys 0.052s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918100,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":599,"lbm_read_time_us":12146,"lbm_reads_lt_1ms":668,"lbm_write_time_us":30532,"lbm_writes_lt_1ms":643,"mutex_wait_us":299,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":27648,"update_count":3000}
I20260812 06:18:35.690303  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=18.063937
I20260812 06:18:35.753965  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.064s	user 0.030s	sys 0.031s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":30253,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:18:35.754505  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=2.188937
I20260812 06:18:35.764573  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3516,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:35.765175  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling MajorDeltaCompactionOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=1.000000
I20260812 06:18:35.960227  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: MajorDeltaCompactionOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.195s	user 0.133s	sys 0.059s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918100,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":599,"lbm_read_time_us":12884,"lbm_reads_lt_1ms":672,"lbm_write_time_us":32156,"lbm_writes_lt_1ms":643,"mutex_wait_us":23,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":9344,"update_count":3000}
I20260812 06:18:35.960790  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=16.079562
I20260812 06:18:36.004993  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.044s	user 0.033s	sys 0.011s Metrics: {"bytes_written":18297009,"delete_count":0,"lbm_write_time_us":19498,"lbm_writes_lt_1ms":449,"reinsert_count":0,"update_count":2230}
I20260812 06:18:36.005553  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=1.196750
I20260812 06:18:36.023185  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.017s	user 0.001s	sys 0.008s Metrics: {"bytes_written":2625758,"delete_count":0,"lbm_write_time_us":3962,"lbm_writes_lt_1ms":67,"reinsert_count":0,"update_count":320}
I20260812 06:18:36.023605  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=2.188937
I20260812 06:18:36.032809  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.009s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3466,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:36.033226  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling MajorDeltaCompactionOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=1.000000
I20260812 06:18:36.220804  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: MajorDeltaCompactionOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.187s	user 0.125s	sys 0.059s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918167,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":851,"lbm_read_time_us":11887,"lbm_reads_lt_1ms":673,"lbm_write_time_us":29032,"lbm_writes_lt_1ms":643,"mutex_wait_us":261,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":3000}
I20260812 06:18:36.221457  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=16.079562
I20260812 06:18:36.267536  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.046s	user 0.030s	sys 0.013s Metrics: {"bytes_written":18091890,"delete_count":0,"lbm_write_time_us":20004,"lbm_writes_lt_1ms":444,"reinsert_count":0,"update_count":2205}
I20260812 06:18:36.267997  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=1.196750
I20260812 06:18:36.283347  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.015s	user 0.007s	sys 0.000s Metrics: {"bytes_written":2830884,"delete_count":0,"lbm_write_time_us":2834,"lbm_writes_lt_1ms":72,"reinsert_count":0,"update_count":345}
I20260812 06:18:36.283798  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=2.188937
I20260812 06:18:36.293224  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.009s	user 0.007s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3403,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:36.293740  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling MajorDeltaCompactionOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=1.000000
I20260812 06:18:36.492293  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: MajorDeltaCompactionOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.198s	user 0.120s	sys 0.078s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918174,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":677,"lbm_read_time_us":14322,"lbm_reads_lt_1ms":673,"lbm_write_time_us":31616,"lbm_writes_lt_1ms":643,"mutex_wait_us":84,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":3000}
I20260812 06:18:36.494839  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=14.095187
I20260812 06:18:36.534001  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.039s	user 0.023s	sys 0.014s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":16570,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:36.534525  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=2.188937
I20260812 06:18:36.549573  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.015s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5654,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:36.550086  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling FlushMRSOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=1.000000
I20260812 06:18:36.577116  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: FlushMRSOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.027s	user 0.025s	sys 0.001s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":55,"dirs.run_cpu_time_us":210,"dirs.run_wall_time_us":1308,"drs_written":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1401,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:18:36.577872  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling LogGCOp(cf8c89e6ee6f4ed68ce9f8452c24f747): free 112239329 bytes of WAL
I20260812 06:18:36.578140  4379 log_reader.cc:385] T cf8c89e6ee6f4ed68ce9f8452c24f747: removed 11 log segments from log reader
I20260812 06:18:36.578202  4379 log.cc:1079] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/cf8c89e6ee6f4ed68ce9f8452c24f747/wal-000000015 (ops 72-76)
I20260812 06:18:36.578243  4379 log.cc:1079] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/cf8c89e6ee6f4ed68ce9f8452c24f747/wal-000000016 (ops 77-80)
I20260812 06:18:36.578277  4379 log.cc:1079] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/cf8c89e6ee6f4ed68ce9f8452c24f747/wal-000000017 (ops 81-85)
I20260812 06:18:36.578302  4379 log.cc:1079] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/cf8c89e6ee6f4ed68ce9f8452c24f747/wal-000000018 (ops 86-90)
I20260812 06:18:36.578336  4379 log.cc:1079] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/cf8c89e6ee6f4ed68ce9f8452c24f747/wal-000000019 (ops 91-95)
I20260812 06:18:36.578379  4379 log.cc:1079] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/cf8c89e6ee6f4ed68ce9f8452c24f747/wal-000000020 (ops 96-100)
I20260812 06:18:36.578411  4379 log.cc:1079] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/cf8c89e6ee6f4ed68ce9f8452c24f747/wal-000000021 (ops 101-105)
I20260812 06:18:36.578438  4379 log.cc:1079] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/cf8c89e6ee6f4ed68ce9f8452c24f747/wal-000000022 (ops 106-110)
I20260812 06:18:36.578469  4379 log.cc:1079] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/cf8c89e6ee6f4ed68ce9f8452c24f747/wal-000000023 (ops 111-115)
I20260812 06:18:36.578500  4379 log.cc:1079] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/cf8c89e6ee6f4ed68ce9f8452c24f747/wal-000000024 (ops 116-120)
I20260812 06:18:36.578523  4379 log.cc:1079] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/cf8c89e6ee6f4ed68ce9f8452c24f747/wal-000000025 (ops 121-125)
I20260812 06:18:36.599064  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: LogGCOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.021s	user 0.000s	sys 0.018s Metrics: {}
I20260812 06:18:36.599527  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=3.181125
I20260812 06:18:36.620796  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.021s	user 0.016s	sys 0.000s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":6530,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:36.621255  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=2.188937
I20260812 06:18:36.630406  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.009s	user 0.007s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3194,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:36.631006  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling UndoDeltaBlockGCOp(cf8c89e6ee6f4ed68ce9f8452c24f747): 461 bytes on disk
I20260812 06:18:36.631652  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: UndoDeltaBlockGCOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":96,"lbm_reads_lt_1ms":4}
I20260812 06:18:36.632252  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling MajorDeltaCompactionOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=1.000000
I20260812 06:18:36.851195  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: MajorDeltaCompactionOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.219s	user 0.150s	sys 0.063s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020732,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":2185,"lbm_read_time_us":14074,"lbm_reads_lt_1ms":774,"lbm_write_time_us":35284,"lbm_writes_lt_1ms":743,"mutex_wait_us":38,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":6656,"thread_start_us":73,"threads_started":1,"update_count":3500}
I20260812 06:18:36.851794  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=18.063937
I20260812 06:18:36.903499  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.052s	user 0.037s	sys 0.011s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":22620,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:36.904066  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=2.188937
I20260812 06:18:36.918413  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.014s	user 0.005s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5362,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:36.918859  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling MajorDeltaCompactionOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=1.000000
I20260812 06:18:37.080499  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: MajorDeltaCompactionOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.161s	user 0.134s	sys 0.024s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918097,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1103,"lbm_read_time_us":10209,"lbm_reads_lt_1ms":668,"lbm_write_time_us":33254,"lbm_writes_lt_1ms":643,"mutex_wait_us":324,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":10368,"update_count":3000}
I20260812 06:18:37.081079  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=14.095187
I20260812 06:18:37.127966  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.047s	user 0.018s	sys 0.025s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":20906,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:37.128631  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=2.188937
I20260812 06:18:37.143949  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.015s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4440,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:37.144455  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling MajorDeltaCompactionOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=1.000000
I20260812 06:18:37.289664  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: MajorDeltaCompactionOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.145s	user 0.095s	sys 0.050s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815686,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":216,"lbm_read_time_us":10854,"lbm_reads_lt_1ms":564,"lbm_write_time_us":24574,"lbm_writes_lt_1ms":543,"mutex_wait_us":47,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2500}
I20260812 06:18:37.290313  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=14.095187
I20260812 06:18:37.329998  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.039s	user 0.022s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17037,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:37.330647  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling MajorDeltaCompactionOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=1.000000
I20260812 06:18:37.472256  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: MajorDeltaCompactionOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.141s	user 0.069s	sys 0.060s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713152,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":481,"lbm_read_time_us":9032,"lbm_reads_lt_1ms":467,"lbm_write_time_us":20087,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10240,"update_count":2000}
I20260812 06:18:37.472884  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=14.095187
I20260812 06:18:37.521497  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.048s	user 0.040s	sys 0.007s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":22609,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:37.521970  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=2.188937
I20260812 06:18:37.537438  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5917,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:37.537916  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling MajorDeltaCompactionOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=1.000000
I20260812 06:18:37.704603  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: MajorDeltaCompactionOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.167s	user 0.109s	sys 0.051s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815680,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":158,"lbm_read_time_us":10930,"lbm_reads_lt_1ms":564,"lbm_write_time_us":24691,"lbm_writes_lt_1ms":543,"mutex_wait_us":44,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":2500}
I20260812 06:18:37.705159  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=14.095187
I20260812 06:18:37.754065  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.049s	user 0.019s	sys 0.020s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":17354,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:37.754634  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=2.188937
I20260812 06:18:37.765498  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4015,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:37.766141  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling MajorDeltaCompactionOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=1.000000
I20260812 06:18:37.923998  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: MajorDeltaCompactionOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.158s	user 0.112s	sys 0.039s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":782,"lbm_read_time_us":11458,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29402,"lbm_writes_lt_1ms":543,"mutex_wait_us":73,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:18:37.924574  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=11.118625
I20260812 06:18:37.969563  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.045s	user 0.023s	sys 0.016s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":19175,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":311,"reinsert_count":0,"update_count":1550}
I20260812 06:18:37.970511  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=2.188937
I20260812 06:18:37.987421  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.017s	user 0.003s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6282,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:37.987872  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=2.188937
I20260812 06:18:37.996851  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3205,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:37.997298  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling FlushMRSOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=1.000000
I20260812 06:18:38.029851  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: FlushMRSOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.032s	user 0.027s	sys 0.004s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":70,"dirs.run_cpu_time_us":231,"dirs.run_wall_time_us":1103,"drs_written":1,"lbm_read_time_us":95,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2059,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:38.030486  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling LogGCOp(cf8c89e6ee6f4ed68ce9f8452c24f747): free 136728502 bytes of WAL
I20260812 06:18:38.030695  4379 log_reader.cc:385] T cf8c89e6ee6f4ed68ce9f8452c24f747: removed 13 log segments from log reader
I20260812 06:18:38.030740  4379 log.cc:1079] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/cf8c89e6ee6f4ed68ce9f8452c24f747/wal-000000026 (ops 126-130)
I20260812 06:18:38.030768  4379 log.cc:1079] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/cf8c89e6ee6f4ed68ce9f8452c24f747/wal-000000027 (ops 131-135)
I20260812 06:18:38.030798  4379 log.cc:1079] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/cf8c89e6ee6f4ed68ce9f8452c24f747/wal-000000028 (ops 136-140)
I20260812 06:18:38.030830  4379 log.cc:1079] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/cf8c89e6ee6f4ed68ce9f8452c24f747/wal-000000029 (ops 141-145)
I20260812 06:18:38.030864  4379 log.cc:1079] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/cf8c89e6ee6f4ed68ce9f8452c24f747/wal-000000030 (ops 146-150)
I20260812 06:18:38.030898  4379 log.cc:1079] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/cf8c89e6ee6f4ed68ce9f8452c24f747/wal-000000031 (ops 151-155)
I20260812 06:18:38.030930  4379 log.cc:1079] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/cf8c89e6ee6f4ed68ce9f8452c24f747/wal-000000032 (ops 156-160)
I20260812 06:18:38.030961  4379 log.cc:1079] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/cf8c89e6ee6f4ed68ce9f8452c24f747/wal-000000033 (ops 161-165)
I20260812 06:18:38.030993  4379 log.cc:1079] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/cf8c89e6ee6f4ed68ce9f8452c24f747/wal-000000034 (ops 166-170)
I20260812 06:18:38.031025  4379 log.cc:1079] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/cf8c89e6ee6f4ed68ce9f8452c24f747/wal-000000035 (ops 171-175)
I20260812 06:18:38.031056  4379 log.cc:1079] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/cf8c89e6ee6f4ed68ce9f8452c24f747/wal-000000036 (ops 176-180)
I20260812 06:18:38.031087  4379 log.cc:1079] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/cf8c89e6ee6f4ed68ce9f8452c24f747/wal-000000037 (ops 181-185)
I20260812 06:18:38.031118  4379 log.cc:1079] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732: Deleting log segment in path: /tmp/dist-test-taskigYs9B/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515508427787-3841-0/minicluster-data/ts-0-root/wals/cf8c89e6ee6f4ed68ce9f8452c24f747/wal-000000038 (ops 186-190)
I20260812 06:18:38.056372  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: LogGCOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.026s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:18:38.056826  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=3.181125
I20260812 06:18:38.084904  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.028s	user 0.013s	sys 0.013s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":6644,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:38.085413  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=2.188937
I20260812 06:18:38.095007  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3538,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:38.095453  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling MajorDeltaCompactionOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=1.000000
I20260812 06:18:38.244936  3841 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.563s	user 1.670s	sys 0.151s
I20260812 06:18:38.334036  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: MajorDeltaCompactionOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.238s	user 0.168s	sys 0.071s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":33020844,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":741,"lbm_read_time_us":14591,"lbm_reads_lt_1ms":771,"lbm_write_time_us":40206,"lbm_writes_lt_1ms":743,"mutex_wait_us":31,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":8832,"thread_start_us":84,"threads_started":1,"update_count":3500}
I20260812 06:18:38.334638  4488 maintenance_manager.cc:419] P bbe3363593bf4084a00970efb79c5732: Scheduling FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747): perf score=10.126437
I20260812 06:18:38.351985  3841 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.107s	user 0.001s	sys 0.000s
I20260812 06:18:38.352573  3841 tablet_server.cc:179] TabletServer@127.3.192.65:0 shutting down...
I20260812 06:18:38.373340  4379 maintenance_manager.cc:643] P bbe3363593bf4084a00970efb79c5732: FlushDeltaMemStoresOp(cf8c89e6ee6f4ed68ce9f8452c24f747) complete. Timing: real 0.038s	user 0.017s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16271,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:38.373847  3841 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:38.374038  3841 tablet_replica.cc:333] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732: stopping tablet replica
I20260812 06:18:38.374155  3841 raft_consensus.cc:2243] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:38.384483  3841 raft_consensus.cc:2272] T cf8c89e6ee6f4ed68ce9f8452c24f747 P bbe3363593bf4084a00970efb79c5732 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:38.398907  3841 tablet_server.cc:196] TabletServer@127.3.192.65:0 shutdown complete.
I20260812 06:18:38.401666  3841 master.cc:562] Master@127.3.192.126:44715 shutting down...
I20260812 06:18:38.404708  3841 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 3661292cf58740048e52f10d4c68d90c [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:38.404857  3841 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 3661292cf58740048e52f10d4c68d90c [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:38.404927  3841 tablet_replica.cc:333] T 00000000000000000000000000000000 P 3661292cf58740048e52f10d4c68d90c: stopping tablet replica
I20260812 06:18:38.417030  3841 master.cc:584] Master@127.3.192.126:44715 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (4986 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10052 ms total)

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