[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:17:34.327173  4296 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.4.50.62:37273
I20260812 06:17:34.328107  4296 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:17:34.328722  4296 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:34.334900  4305 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:34.335012  4296 server_base.cc:1061] running on GCE node
W20260812 06:17:34.334934  4302 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:34.335186  4301 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:34.335655  4296 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:34.335757  4296 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:34.335803  4296 hybrid_clock.cc:648] HybridClock initialized: now 1786515454335801 us; error 0 us; skew 500 ppm
I20260812 06:17:34.337368  4296 webserver.cc:533] Webserver started at http://127.4.50.62:45577/ using document root <none> and password file <none>
I20260812 06:17:34.337859  4296 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:34.337915  4296 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:34.338179  4296 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:34.339712  4296 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454317672-4296-0/minicluster-data/master-0-root/instance:
uuid: "37db1145e74a4a69b26c5115de5b14fe"
format_stamp: "Formatted at 2026-08-12 06:17:34 on dist-test-slave-7c35"
I20260812 06:17:34.342976  4296 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:17:34.344794  4312 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:34.345692  4296 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:34.345816  4296 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454317672-4296-0/minicluster-data/master-0-root
uuid: "37db1145e74a4a69b26c5115de5b14fe"
format_stamp: "Formatted at 2026-08-12 06:17:34 on dist-test-slave-7c35"
I20260812 06:17:34.345917  4296 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454317672-4296-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454317672-4296-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454317672-4296-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:34.369853  4296 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:34.370484  4296 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:17:34.370663  4296 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:34.377942  4296 rpc_server.cc:307] RPC server started. Bound to: 127.4.50.62:37273
I20260812 06:17:34.377948  4383 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.4.50.62:37273 every 8 connection(s)
I20260812 06:17:34.380059  4384 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:34.385020  4384 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 37db1145e74a4a69b26c5115de5b14fe: Bootstrap starting.
I20260812 06:17:34.387243  4384 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 37db1145e74a4a69b26c5115de5b14fe: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:34.388062  4384 log.cc:826] T 00000000000000000000000000000000 P 37db1145e74a4a69b26c5115de5b14fe: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:34.389493  4384 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 37db1145e74a4a69b26c5115de5b14fe: No bootstrap required, opened a new log
I20260812 06:17:34.392030  4384 raft_consensus.cc:359] T 00000000000000000000000000000000 P 37db1145e74a4a69b26c5115de5b14fe [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "37db1145e74a4a69b26c5115de5b14fe" member_type: VOTER }
I20260812 06:17:34.392176  4384 raft_consensus.cc:385] T 00000000000000000000000000000000 P 37db1145e74a4a69b26c5115de5b14fe [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:34.392213  4384 raft_consensus.cc:740] T 00000000000000000000000000000000 P 37db1145e74a4a69b26c5115de5b14fe [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 37db1145e74a4a69b26c5115de5b14fe, State: Initialized, Role: FOLLOWER
I20260812 06:17:34.392678  4384 consensus_queue.cc:260] T 00000000000000000000000000000000 P 37db1145e74a4a69b26c5115de5b14fe [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: "37db1145e74a4a69b26c5115de5b14fe" member_type: VOTER }
I20260812 06:17:34.392794  4384 raft_consensus.cc:399] T 00000000000000000000000000000000 P 37db1145e74a4a69b26c5115de5b14fe [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:34.392836  4384 raft_consensus.cc:493] T 00000000000000000000000000000000 P 37db1145e74a4a69b26c5115de5b14fe [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:34.392912  4384 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 37db1145e74a4a69b26c5115de5b14fe [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:34.393653  4384 raft_consensus.cc:515] T 00000000000000000000000000000000 P 37db1145e74a4a69b26c5115de5b14fe [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "37db1145e74a4a69b26c5115de5b14fe" member_type: VOTER }
I20260812 06:17:34.394042  4384 leader_election.cc:304] T 00000000000000000000000000000000 P 37db1145e74a4a69b26c5115de5b14fe [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: 37db1145e74a4a69b26c5115de5b14fe; no voters: 
I20260812 06:17:34.394270  4384 leader_election.cc:290] T 00000000000000000000000000000000 P 37db1145e74a4a69b26c5115de5b14fe [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:34.394414  4387 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 37db1145e74a4a69b26c5115de5b14fe [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:34.394665  4387 raft_consensus.cc:697] T 00000000000000000000000000000000 P 37db1145e74a4a69b26c5115de5b14fe [term 1 LEADER]: Becoming Leader. State: Replica: 37db1145e74a4a69b26c5115de5b14fe, State: Running, Role: LEADER
I20260812 06:17:34.395084  4387 consensus_queue.cc:237] T 00000000000000000000000000000000 P 37db1145e74a4a69b26c5115de5b14fe [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: "37db1145e74a4a69b26c5115de5b14fe" member_type: VOTER }
I20260812 06:17:34.395197  4384 sys_catalog.cc:565] T 00000000000000000000000000000000 P 37db1145e74a4a69b26c5115de5b14fe [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:34.396858  4388 sys_catalog.cc:455] T 00000000000000000000000000000000 P 37db1145e74a4a69b26c5115de5b14fe [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "37db1145e74a4a69b26c5115de5b14fe" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "37db1145e74a4a69b26c5115de5b14fe" member_type: VOTER } }
I20260812 06:17:34.396893  4389 sys_catalog.cc:455] T 00000000000000000000000000000000 P 37db1145e74a4a69b26c5115de5b14fe [sys.catalog]: SysCatalogTable state changed. Reason: New leader 37db1145e74a4a69b26c5115de5b14fe. Latest consensus state: current_term: 1 leader_uuid: "37db1145e74a4a69b26c5115de5b14fe" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "37db1145e74a4a69b26c5115de5b14fe" member_type: VOTER } }
I20260812 06:17:34.396961  4388 sys_catalog.cc:458] T 00000000000000000000000000000000 P 37db1145e74a4a69b26c5115de5b14fe [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:34.396996  4389 sys_catalog.cc:458] T 00000000000000000000000000000000 P 37db1145e74a4a69b26c5115de5b14fe [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:34.397365  4403 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:34.397581  4296 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:34.399473  4403 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:34.403757  4403 catalog_manager.cc:1383] Generated new cluster ID: e8f1b7de0e964241bfb60f41fae82ab1
I20260812 06:17:34.403815  4403 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:34.416291  4403 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:34.417322  4403 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:34.432020  4403 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 37db1145e74a4a69b26c5115de5b14fe: Generated new TSK 0
I20260812 06:17:34.432659  4403 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:34.462184  4296 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:34.464879  4415 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:34.464948  4412 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:34.464960  4413 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:34.465543  4296 server_base.cc:1061] running on GCE node
I20260812 06:17:34.465718  4296 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:34.465765  4296 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:34.465782  4296 hybrid_clock.cc:648] HybridClock initialized: now 1786515454465782 us; error 0 us; skew 500 ppm
I20260812 06:17:34.466773  4296 webserver.cc:533] Webserver started at http://127.4.50.1:45847/ using document root <none> and password file <none>
I20260812 06:17:34.466977  4296 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:34.467027  4296 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:34.467119  4296 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:34.467507  4296 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454317672-4296-0/minicluster-data/ts-0-root/instance:
uuid: "ec1884233b374114abf220c4d24fbc05"
format_stamp: "Formatted at 2026-08-12 06:17:34 on dist-test-slave-7c35"
I20260812 06:17:34.468978  4296 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:34.469941  4421 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:34.470222  4296 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:34.470293  4296 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454317672-4296-0/minicluster-data/ts-0-root
uuid: "ec1884233b374114abf220c4d24fbc05"
format_stamp: "Formatted at 2026-08-12 06:17:34 on dist-test-slave-7c35"
I20260812 06:17:34.470379  4296 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454317672-4296-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454317672-4296-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454317672-4296-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:34.482146  4296 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:34.482497  4296 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:34.482957  4296 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:34.483769  4296 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:34.483820  4296 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:34.483882  4296 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:34.483923  4296 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:34.490743  4296 rpc_server.cc:307] RPC server started. Bound to: 127.4.50.1:44825
I20260812 06:17:34.490779  4498 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.4.50.1:44825 every 8 connection(s)
I20260812 06:17:34.504609  4500 heartbeater.cc:344] Connected to a master server at 127.4.50.62:37273
I20260812 06:17:34.504858  4500 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:34.505265  4500 heartbeater.cc:507] Master 127.4.50.62:37273 requested a full tablet report, sending...
I20260812 06:17:34.506584  4336 ts_manager.cc:194] Registered new tserver with Master: ec1884233b374114abf220c4d24fbc05 (127.4.50.1:44825)
I20260812 06:17:34.506963  4296 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.01558564s
I20260812 06:17:34.508116  4336 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:60906
I20260812 06:17:34.515637  4336 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:60922:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:17:34.528908  4456 tablet_service.cc:1511] Processing CreateTablet for tablet 3b5ccc4454bb4e1cb9e22fae9cf14ebc (DEFAULT_TABLE table=heavy-update-compaction-test [id=b5446d61c1d14b89b6772c7094bdecdd]), partition=
I20260812 06:17:34.529311  4456 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 3b5ccc4454bb4e1cb9e22fae9cf14ebc. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:34.531580  4515 tablet_bootstrap.cc:492] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc P ec1884233b374114abf220c4d24fbc05: Bootstrap starting.
I20260812 06:17:34.532581  4515 tablet_bootstrap.cc:654] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc P ec1884233b374114abf220c4d24fbc05: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:34.534082  4515 tablet_bootstrap.cc:492] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc P ec1884233b374114abf220c4d24fbc05: No bootstrap required, opened a new log
I20260812 06:17:34.534188  4515 ts_tablet_manager.cc:1403] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc P ec1884233b374114abf220c4d24fbc05: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:17:34.534605  4515 raft_consensus.cc:359] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc P ec1884233b374114abf220c4d24fbc05 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ec1884233b374114abf220c4d24fbc05" member_type: VOTER last_known_addr { host: "127.4.50.1" port: 44825 } }
I20260812 06:17:34.534713  4515 raft_consensus.cc:385] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc P ec1884233b374114abf220c4d24fbc05 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:34.534772  4515 raft_consensus.cc:740] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc P ec1884233b374114abf220c4d24fbc05 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: ec1884233b374114abf220c4d24fbc05, State: Initialized, Role: FOLLOWER
I20260812 06:17:34.534929  4515 consensus_queue.cc:260] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc P ec1884233b374114abf220c4d24fbc05 [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: "ec1884233b374114abf220c4d24fbc05" member_type: VOTER last_known_addr { host: "127.4.50.1" port: 44825 } }
I20260812 06:17:34.535043  4515 raft_consensus.cc:399] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc P ec1884233b374114abf220c4d24fbc05 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:34.535090  4515 raft_consensus.cc:493] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc P ec1884233b374114abf220c4d24fbc05 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:34.535142  4515 raft_consensus.cc:3060] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc P ec1884233b374114abf220c4d24fbc05 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:34.535812  4515 raft_consensus.cc:515] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc P ec1884233b374114abf220c4d24fbc05 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ec1884233b374114abf220c4d24fbc05" member_type: VOTER last_known_addr { host: "127.4.50.1" port: 44825 } }
I20260812 06:17:34.535956  4515 leader_election.cc:304] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc P ec1884233b374114abf220c4d24fbc05 [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: ec1884233b374114abf220c4d24fbc05; no voters: 
I20260812 06:17:34.536207  4515 leader_election.cc:290] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc P ec1884233b374114abf220c4d24fbc05 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:34.536316  4518 raft_consensus.cc:2804] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc P ec1884233b374114abf220c4d24fbc05 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:34.536578  4515 ts_tablet_manager.cc:1434] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc P ec1884233b374114abf220c4d24fbc05: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:17:34.536500  4518 raft_consensus.cc:697] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc P ec1884233b374114abf220c4d24fbc05 [term 1 LEADER]: Becoming Leader. State: Replica: ec1884233b374114abf220c4d24fbc05, State: Running, Role: LEADER
I20260812 06:17:34.537009  4500 heartbeater.cc:499] Master 127.4.50.62:37273 was elected leader, sending a full tablet report...
I20260812 06:17:34.537434  4518 consensus_queue.cc:237] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc P ec1884233b374114abf220c4d24fbc05 [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: "ec1884233b374114abf220c4d24fbc05" member_type: VOTER last_known_addr { host: "127.4.50.1" port: 44825 } }
I20260812 06:17:34.539788  4336 catalog_manager.cc:5719] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc P ec1884233b374114abf220c4d24fbc05 reported cstate change: term changed from 0 to 1, leader changed from <none> to ec1884233b374114abf220c4d24fbc05 (127.4.50.1). New cstate: current_term: 1 leader_uuid: "ec1884233b374114abf220c4d24fbc05" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ec1884233b374114abf220c4d24fbc05" member_type: VOTER last_known_addr { host: "127.4.50.1" port: 44825 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:34.599694  4296 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.050s	user 0.016s	sys 0.007s
I20260812 06:17:34.741863  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling FlushMRSOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=19.054940
I20260812 06:17:34.908612  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: FlushMRSOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.166s	user 0.133s	sys 0.031s Metrics: {"bytes_written":12758763,"cfile_init":1,"compiler_manager_pool.queue_time_us":297,"delete_count":0,"dirs.queue_time_us":50,"dirs.run_cpu_time_us":191,"dirs.run_wall_time_us":2171,"drs_written":1,"lbm_read_time_us":127,"lbm_reads_lt_1ms":4,"lbm_write_time_us":38556,"lbm_writes_lt_1ms":768,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":261504,"thread_start_us":204,"threads_started":1,"update_count":1555}
I20260812 06:17:34.909931  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling LogGCOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): free 20743880 bytes of WAL
I20260812 06:17:34.910313  4427 log_reader.cc:385] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc: removed 2 log segments from log reader
I20260812 06:17:34.910377  4427 log.cc:1079] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc P ec1884233b374114abf220c4d24fbc05: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/3b5ccc4454bb4e1cb9e22fae9cf14ebc/wal-000000001 (ops 1-6)
I20260812 06:17:34.910445  4427 log.cc:1079] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc P ec1884233b374114abf220c4d24fbc05: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/3b5ccc4454bb4e1cb9e22fae9cf14ebc/wal-000000002 (ops 7-11)
I20260812 06:17:34.915601  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: LogGCOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.005s	user 0.000s	sys 0.005s Metrics: {}
I20260812 06:17:34.915961  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling UndoDeltaBlockGCOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): 16411393 bytes on disk
I20260812 06:17:34.916529  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: UndoDeltaBlockGCOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4}
I20260812 06:17:34.917095  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=2.188937
I20260812 06:17:34.950963  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.034s	user 0.006s	sys 0.012s Metrics: {"bytes_written":4061634,"delete_count":0,"lbm_write_time_us":3823,"lbm_writes_lt_1ms":102,"reinsert_count":0,"update_count":495}
I20260812 06:17:34.951399  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=2.188937
I20260812 06:17:34.965019  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.013s	user 0.007s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5046,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:34.965649  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling MajorDeltaCompactionOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=1.000000
I20260812 06:17:35.130514  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: MajorDeltaCompactionOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.165s	user 0.109s	sys 0.056s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774802,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":88,"lbm_read_time_us":12510,"lbm_reads_lt_1ms":569,"lbm_write_time_us":27347,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1280,"thread_start_us":347,"threads_started":5,"update_count":2500}
I20260812 06:17:35.131603  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=10.126437
I20260812 06:17:35.190953  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.059s	user 0.039s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18306,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:35.191540  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=2.188937
I20260812 06:17:35.203601  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.012s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4544,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.204106  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling MajorDeltaCompactionOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=1.000000
I20260812 06:17:35.333395  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: MajorDeltaCompactionOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.129s	user 0.097s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":221,"lbm_read_time_us":9287,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23553,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11264,"update_count":2000}
I20260812 06:17:35.334074  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=10.126437
I20260812 06:17:35.373792  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.040s	user 0.019s	sys 0.011s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15243,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:35.374229  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=2.188937
I20260812 06:17:35.388983  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5641,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.389470  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling MajorDeltaCompactionOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=1.000000
I20260812 06:17:35.508342  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: MajorDeltaCompactionOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.119s	user 0.089s	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":709,"lbm_read_time_us":8073,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22506,"lbm_writes_lt_1ms":443,"mutex_wait_us":65,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2000}
I20260812 06:17:35.508960  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=10.126437
I20260812 06:17:35.553948  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.045s	user 0.016s	sys 0.015s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":15017,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:35.554389  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=2.188937
I20260812 06:17:35.564638  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3886,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.565270  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling MajorDeltaCompactionOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=1.000000
I20260812 06:17:35.687273  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: MajorDeltaCompactionOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.122s	user 0.090s	sys 0.031s 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":190,"lbm_read_time_us":8569,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23189,"lbm_writes_lt_1ms":443,"mutex_wait_us":38,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:17:35.687834  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=10.126437
I20260812 06:17:35.736052  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.048s	user 0.035s	sys 0.011s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":15425,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:35.736606  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=2.188937
I20260812 06:17:35.753006  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.016s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6025,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.753623  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling MajorDeltaCompactionOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=1.000000
I20260812 06:17:35.893213  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: MajorDeltaCompactionOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.139s	user 0.100s	sys 0.039s 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":305,"lbm_read_time_us":11317,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22078,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":2000}
I20260812 06:17:35.893859  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=10.126437
I20260812 06:17:35.940231  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.046s	user 0.031s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":21574,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:17:35.940658  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=2.188937
I20260812 06:17:35.950660  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3852,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.951110  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling MajorDeltaCompactionOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=1.000000
I20260812 06:17:36.077268  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: MajorDeltaCompactionOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.126s	user 0.099s	sys 0.026s 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":776,"lbm_read_time_us":8826,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23909,"lbm_writes_lt_1ms":443,"mutex_wait_us":241,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:17:36.077855  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=10.126437
I20260812 06:17:36.118672  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.041s	user 0.014s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14279,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:36.119213  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=2.188937
I20260812 06:17:36.131518  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4531,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:36.132030  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling FlushMRSOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=1.000000
I20260812 06:17:36.165213  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: FlushMRSOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.033s	user 0.027s	sys 0.004s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":130,"dirs.run_cpu_time_us":228,"dirs.run_wall_time_us":1322,"drs_written":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2222,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:36.166045  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling LogGCOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): free 115943178 bytes of WAL
I20260812 06:17:36.166328  4427 log_reader.cc:385] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc: removed 11 log segments from log reader
I20260812 06:17:36.166405  4427 log.cc:1079] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc P ec1884233b374114abf220c4d24fbc05: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/3b5ccc4454bb4e1cb9e22fae9cf14ebc/wal-000000003 (ops 12-16)
I20260812 06:17:36.166450  4427 log.cc:1079] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc P ec1884233b374114abf220c4d24fbc05: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/3b5ccc4454bb4e1cb9e22fae9cf14ebc/wal-000000004 (ops 17-21)
I20260812 06:17:36.166481  4427 log.cc:1079] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc P ec1884233b374114abf220c4d24fbc05: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/3b5ccc4454bb4e1cb9e22fae9cf14ebc/wal-000000005 (ops 22-26)
I20260812 06:17:36.166524  4427 log.cc:1079] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc P ec1884233b374114abf220c4d24fbc05: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/3b5ccc4454bb4e1cb9e22fae9cf14ebc/wal-000000006 (ops 27-31)
I20260812 06:17:36.166563  4427 log.cc:1079] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc P ec1884233b374114abf220c4d24fbc05: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/3b5ccc4454bb4e1cb9e22fae9cf14ebc/wal-000000007 (ops 32-36)
I20260812 06:17:36.166594  4427 log.cc:1079] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc P ec1884233b374114abf220c4d24fbc05: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/3b5ccc4454bb4e1cb9e22fae9cf14ebc/wal-000000008 (ops 37-41)
I20260812 06:17:36.166635  4427 log.cc:1079] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc P ec1884233b374114abf220c4d24fbc05: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/3b5ccc4454bb4e1cb9e22fae9cf14ebc/wal-000000009 (ops 42-46)
I20260812 06:17:36.166666  4427 log.cc:1079] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc P ec1884233b374114abf220c4d24fbc05: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/3b5ccc4454bb4e1cb9e22fae9cf14ebc/wal-000000010 (ops 47-51)
I20260812 06:17:36.166698  4427 log.cc:1079] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc P ec1884233b374114abf220c4d24fbc05: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/3b5ccc4454bb4e1cb9e22fae9cf14ebc/wal-000000011 (ops 52-56)
I20260812 06:17:36.166736  4427 log.cc:1079] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc P ec1884233b374114abf220c4d24fbc05: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/3b5ccc4454bb4e1cb9e22fae9cf14ebc/wal-000000012 (ops 57-61)
I20260812 06:17:36.166775  4427 log.cc:1079] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc P ec1884233b374114abf220c4d24fbc05: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/3b5ccc4454bb4e1cb9e22fae9cf14ebc/wal-000000013 (ops 62-66)
I20260812 06:17:36.193843  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: LogGCOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.028s	user 0.002s	sys 0.023s Metrics: {}
I20260812 06:17:36.194334  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=3.181125
I20260812 06:17:36.208441  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.014s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":5349,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:36.208899  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling UndoDeltaBlockGCOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): 462 bytes on disk
I20260812 06:17:36.209425  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: UndoDeltaBlockGCOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":74,"lbm_reads_lt_1ms":4}
I20260812 06:17:36.209888  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=2.188937
I20260812 06:17:36.219429  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.009s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3451,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:36.220026  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling MajorDeltaCompactionOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=1.000000
I20260812 06:17:36.396792  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: MajorDeltaCompactionOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.177s	user 0.125s	sys 0.052s 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":569,"lbm_read_time_us":12643,"lbm_reads_lt_1ms":674,"lbm_write_time_us":36827,"lbm_writes_lt_1ms":643,"mutex_wait_us":54,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":9600,"thread_start_us":87,"threads_started":1,"update_count":3000}
I20260812 06:17:36.397429  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=14.095187
I20260812 06:17:36.449600  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.052s	user 0.033s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22950,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:36.450143  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=2.188937
I20260812 06:17:36.462491  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4455,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:36.463083  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling MajorDeltaCompactionOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=1.000000
I20260812 06:17:36.612962  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: MajorDeltaCompactionOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.150s	user 0.086s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":145,"lbm_read_time_us":11083,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28646,"lbm_writes_lt_1ms":543,"mutex_wait_us":40,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5888,"update_count":2500}
I20260812 06:17:36.613479  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=14.095187
I20260812 06:17:36.663743  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.050s	user 0.022s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22595,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:36.664399  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling MajorDeltaCompactionOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=1.000000
I20260812 06:17:36.811533  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: MajorDeltaCompactionOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.147s	user 0.111s	sys 0.036s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":192,"lbm_read_time_us":8484,"lbm_reads_lt_1ms":467,"lbm_write_time_us":27082,"lbm_writes_lt_1ms":443,"mutex_wait_us":29,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16768,"update_count":2000}
I20260812 06:17:36.813419  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=11.118625
I20260812 06:17:36.843211  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.030s	user 0.018s	sys 0.011s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":12822,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:36.843724  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=2.188937
I20260812 06:17:36.859879  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.016s	user 0.004s	sys 0.010s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5693,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:36.860428  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling MajorDeltaCompactionOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=1.000000
I20260812 06:17:36.989185  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: MajorDeltaCompactionOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.129s	user 0.079s	sys 0.049s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672270,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1039,"lbm_read_time_us":8327,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26794,"lbm_writes_lt_1ms":443,"mutex_wait_us":251,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12160,"update_count":2000}
I20260812 06:17:36.989899  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=10.126437
I20260812 06:17:37.029812  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.040s	user 0.024s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14662,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:37.030301  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=2.188937
I20260812 06:17:37.040621  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3892,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:37.041370  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling MajorDeltaCompactionOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=1.000000
I20260812 06:17:37.168375  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: MajorDeltaCompactionOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.127s	user 0.101s	sys 0.026s 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":190,"lbm_read_time_us":9394,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23152,"lbm_writes_lt_1ms":443,"mutex_wait_us":79,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12800,"update_count":2000}
I20260812 06:17:37.169085  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=10.126437
I20260812 06:17:37.213249  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.044s	user 0.026s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17608,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:37.213753  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=2.188937
I20260812 06:17:37.223937  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3991,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:37.224668  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling MajorDeltaCompactionOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=1.000000
I20260812 06:17:37.345335  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: MajorDeltaCompactionOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.120s	user 0.102s	sys 0.018s 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":900,"lbm_read_time_us":7419,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23355,"lbm_writes_lt_1ms":443,"mutex_wait_us":318,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":44672,"update_count":2000}
I20260812 06:17:37.345923  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=10.126437
I20260812 06:17:37.392674  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.047s	user 0.026s	sys 0.015s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":15079,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:37.393172  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=2.188937
I20260812 06:17:37.404699  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4141,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:37.405161  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling MajorDeltaCompactionOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=1.000000
I20260812 06:17:37.550635  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: MajorDeltaCompactionOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.145s	user 0.089s	sys 0.056s 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":979,"lbm_read_time_us":10570,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24356,"lbm_writes_lt_1ms":443,"mutex_wait_us":284,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8448,"update_count":2000}
I20260812 06:17:37.551251  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=10.126437
I20260812 06:17:37.586287  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.035s	user 0.023s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14840,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:37.586783  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=2.188937
I20260812 06:17:37.597414  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.010s	user 0.005s	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:17:37.598215  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling FlushMRSOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=1.000000
I20260812 06:17:37.632721  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: FlushMRSOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.034s	user 0.033s	sys 0.000s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":44,"dirs.run_cpu_time_us":173,"dirs.run_wall_time_us":1300,"drs_written":1,"lbm_read_time_us":71,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1899,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:37.633448  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling LogGCOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): free 133477376 bytes of WAL
I20260812 06:17:37.633672  4427 log_reader.cc:385] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc: removed 13 log segments from log reader
I20260812 06:17:37.633714  4427 log.cc:1079] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc P ec1884233b374114abf220c4d24fbc05: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/3b5ccc4454bb4e1cb9e22fae9cf14ebc/wal-000000014 (ops 67-71)
I20260812 06:17:37.633764  4427 log.cc:1079] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc P ec1884233b374114abf220c4d24fbc05: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/3b5ccc4454bb4e1cb9e22fae9cf14ebc/wal-000000015 (ops 72-76)
I20260812 06:17:37.633809  4427 log.cc:1079] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc P ec1884233b374114abf220c4d24fbc05: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/3b5ccc4454bb4e1cb9e22fae9cf14ebc/wal-000000016 (ops 77-81)
I20260812 06:17:37.633841  4427 log.cc:1079] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc P ec1884233b374114abf220c4d24fbc05: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/3b5ccc4454bb4e1cb9e22fae9cf14ebc/wal-000000017 (ops 82-86)
I20260812 06:17:37.633881  4427 log.cc:1079] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc P ec1884233b374114abf220c4d24fbc05: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/3b5ccc4454bb4e1cb9e22fae9cf14ebc/wal-000000018 (ops 87-91)
I20260812 06:17:37.633930  4427 log.cc:1079] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc P ec1884233b374114abf220c4d24fbc05: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/3b5ccc4454bb4e1cb9e22fae9cf14ebc/wal-000000019 (ops 92-96)
I20260812 06:17:37.633971  4427 log.cc:1079] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc P ec1884233b374114abf220c4d24fbc05: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/3b5ccc4454bb4e1cb9e22fae9cf14ebc/wal-000000020 (ops 97-101)
I20260812 06:17:37.634011  4427 log.cc:1079] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc P ec1884233b374114abf220c4d24fbc05: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/3b5ccc4454bb4e1cb9e22fae9cf14ebc/wal-000000021 (ops 102-106)
I20260812 06:17:37.634052  4427 log.cc:1079] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc P ec1884233b374114abf220c4d24fbc05: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/3b5ccc4454bb4e1cb9e22fae9cf14ebc/wal-000000022 (ops 107-111)
I20260812 06:17:37.634090  4427 log.cc:1079] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc P ec1884233b374114abf220c4d24fbc05: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/3b5ccc4454bb4e1cb9e22fae9cf14ebc/wal-000000023 (ops 112-116)
I20260812 06:17:37.634131  4427 log.cc:1079] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc P ec1884233b374114abf220c4d24fbc05: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/3b5ccc4454bb4e1cb9e22fae9cf14ebc/wal-000000024 (ops 117-121)
I20260812 06:17:37.634171  4427 log.cc:1079] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc P ec1884233b374114abf220c4d24fbc05: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/3b5ccc4454bb4e1cb9e22fae9cf14ebc/wal-000000025 (ops 122-126)
I20260812 06:17:37.634212  4427 log.cc:1079] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc P ec1884233b374114abf220c4d24fbc05: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/3b5ccc4454bb4e1cb9e22fae9cf14ebc/wal-000000026 (ops 127-131)
I20260812 06:17:37.662611  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: LogGCOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.029s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:17:37.663151  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=5.165500
I20260812 06:17:37.687640  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.024s	user 0.008s	sys 0.016s Metrics: {"bytes_written":7302546,"delete_count":0,"lbm_write_time_us":7000,"lbm_writes_lt_1ms":181,"mutex_wait_us":74,"reinsert_count":0,"update_count":890}
I20260812 06:17:37.688212  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling MajorDeltaCompactionOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=1.000000
I20260812 06:17:37.881892  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: MajorDeltaCompactionOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.193s	user 0.127s	sys 0.064s Metrics: {"cfile_cache_miss":611,"cfile_cache_miss_bytes":27974688,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":339,"lbm_read_time_us":13437,"lbm_reads_lt_1ms":647,"lbm_write_time_us":31562,"lbm_writes_lt_1ms":621,"mutex_wait_us":43,"peak_mem_usage":72558934,"reinsert_count":0,"spinlock_wait_cycles":1664,"thread_start_us":79,"threads_started":1,"update_count":2890}
I20260812 06:17:37.882679  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=15.087375
I20260812 06:17:37.944967  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.062s	user 0.034s	sys 0.026s Metrics: {"bytes_written":17312443,"delete_count":0,"lbm_write_time_us":25967,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":423,"reinsert_count":0,"update_count":2110}
I20260812 06:17:37.945726  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling UndoDeltaBlockGCOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): 482 bytes on disk
I20260812 06:17:37.946344  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: UndoDeltaBlockGCOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":95,"lbm_reads_lt_1ms":4}
I20260812 06:17:37.947194  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=2.188937
I20260812 06:17:37.962174  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.015s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4972,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:37.962643  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling MajorDeltaCompactionOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=1.000000
I20260812 06:17:38.143770  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: MajorDeltaCompactionOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.181s	user 0.125s	sys 0.056s Metrics: {"cfile_cache_miss":554,"cfile_cache_miss_bytes":25677230,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":299,"lbm_read_time_us":11974,"lbm_reads_lt_1ms":586,"lbm_write_time_us":31840,"lbm_writes_lt_1ms":565,"mutex_wait_us":21,"peak_mem_usage":65059054,"reinsert_count":0,"spinlock_wait_cycles":10368,"update_count":2610}
I20260812 06:17:38.144435  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=14.095187
I20260812 06:17:38.201829  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.057s	user 0.035s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24858,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:38.202486  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=2.188937
I20260812 06:17:38.222950  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.020s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5742,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:38.223519  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling MajorDeltaCompactionOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=1.000000
I20260812 06:17:38.399737  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: MajorDeltaCompactionOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.176s	user 0.125s	sys 0.051s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":163,"lbm_read_time_us":12646,"lbm_reads_lt_1ms":564,"lbm_write_time_us":33005,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14848,"update_count":2500}
I20260812 06:17:38.400491  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=14.095187
I20260812 06:17:38.454727  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.054s	user 0.020s	sys 0.027s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24518,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:38.455346  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=3.181125
I20260812 06:17:38.477445  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.022s	user 0.012s	sys 0.008s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4836,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:38.477980  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=2.188937
I20260812 06:17:38.494278  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.016s	user 0.006s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6126,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:38.494916  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling MajorDeltaCompactionOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=1.000000
I20260812 06:17:38.693881  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: MajorDeltaCompactionOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.199s	user 0.152s	sys 0.044s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877210,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":229,"lbm_read_time_us":15345,"lbm_reads_lt_1ms":673,"lbm_write_time_us":34071,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12160,"update_count":3000}
I20260812 06:17:38.694639  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=14.095187
I20260812 06:17:38.748821  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.054s	user 0.035s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19530,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:38.749331  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=2.188937
I20260812 06:17:38.760203  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4315,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:38.760620  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling MajorDeltaCompactionOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=1.000000
I20260812 06:17:38.948208  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: MajorDeltaCompactionOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.187s	user 0.124s	sys 0.052s 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":735,"lbm_read_time_us":11945,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30292,"lbm_writes_lt_1ms":543,"mutex_wait_us":269,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7936,"update_count":2500}
I20260812 06:17:38.948920  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=14.095187
I20260812 06:17:39.009176  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.060s	user 0.024s	sys 0.019s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":33043,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:39.009622  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=2.188937
I20260812 06:17:39.020848  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4059,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:39.021564  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling FlushMRSOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=1.000000
I20260812 06:17:39.059008  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: FlushMRSOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.037s	user 0.033s	sys 0.001s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":59,"dirs.run_cpu_time_us":226,"dirs.run_wall_time_us":1448,"drs_written":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1658,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:39.059684  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling LogGCOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): free 112239562 bytes of WAL
I20260812 06:17:39.059932  4427 log_reader.cc:385] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc: removed 11 log segments from log reader
I20260812 06:17:39.059983  4427 log.cc:1079] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc P ec1884233b374114abf220c4d24fbc05: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/3b5ccc4454bb4e1cb9e22fae9cf14ebc/wal-000000027 (ops 132-136)
I20260812 06:17:39.060041  4427 log.cc:1079] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc P ec1884233b374114abf220c4d24fbc05: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/3b5ccc4454bb4e1cb9e22fae9cf14ebc/wal-000000028 (ops 137-141)
I20260812 06:17:39.060094  4427 log.cc:1079] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc P ec1884233b374114abf220c4d24fbc05: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/3b5ccc4454bb4e1cb9e22fae9cf14ebc/wal-000000029 (ops 142-146)
I20260812 06:17:39.060141  4427 log.cc:1079] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc P ec1884233b374114abf220c4d24fbc05: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/3b5ccc4454bb4e1cb9e22fae9cf14ebc/wal-000000030 (ops 147-150)
I20260812 06:17:39.060187  4427 log.cc:1079] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc P ec1884233b374114abf220c4d24fbc05: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/3b5ccc4454bb4e1cb9e22fae9cf14ebc/wal-000000031 (ops 151-155)
I20260812 06:17:39.060240  4427 log.cc:1079] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc P ec1884233b374114abf220c4d24fbc05: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/3b5ccc4454bb4e1cb9e22fae9cf14ebc/wal-000000032 (ops 156-160)
I20260812 06:17:39.060284  4427 log.cc:1079] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc P ec1884233b374114abf220c4d24fbc05: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/3b5ccc4454bb4e1cb9e22fae9cf14ebc/wal-000000033 (ops 161-165)
I20260812 06:17:39.060330  4427 log.cc:1079] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc P ec1884233b374114abf220c4d24fbc05: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/3b5ccc4454bb4e1cb9e22fae9cf14ebc/wal-000000034 (ops 166-170)
I20260812 06:17:39.060384  4427 log.cc:1079] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc P ec1884233b374114abf220c4d24fbc05: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/3b5ccc4454bb4e1cb9e22fae9cf14ebc/wal-000000035 (ops 171-175)
I20260812 06:17:39.060423  4427 log.cc:1079] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc P ec1884233b374114abf220c4d24fbc05: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/3b5ccc4454bb4e1cb9e22fae9cf14ebc/wal-000000036 (ops 176-180)
I20260812 06:17:39.060468  4427 log.cc:1079] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc P ec1884233b374114abf220c4d24fbc05: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/3b5ccc4454bb4e1cb9e22fae9cf14ebc/wal-000000037 (ops 181-185)
I20260812 06:17:39.083902  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: LogGCOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.024s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:17:39.084300  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=3.181125
I20260812 06:17:39.109506  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.025s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":7676,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:39.110001  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling UndoDeltaBlockGCOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): 448 bytes on disk
I20260812 06:17:39.110481  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: UndoDeltaBlockGCOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) 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:17:39.111132  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=2.188937
I20260812 06:17:39.121716  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4035,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:39.122468  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling MajorDeltaCompactionOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=1.000000
I20260812 06:17:39.356504  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: MajorDeltaCompactionOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.234s	user 0.147s	sys 0.076s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979743,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":603,"lbm_read_time_us":16621,"lbm_reads_lt_1ms":774,"lbm_write_time_us":37917,"lbm_writes_lt_1ms":743,"mutex_wait_us":47,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":13312,"thread_start_us":97,"threads_started":1,"update_count":3500}
I20260812 06:17:39.357616  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=18.063937
I20260812 06:17:39.408365  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: FlushDeltaMemStoresOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.050s	user 0.033s	sys 0.015s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":22927,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:39.409025  4502 maintenance_manager.cc:419] P ec1884233b374114abf220c4d24fbc05: Scheduling MajorDeltaCompactionOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc): perf score=1.000000
I20260812 06:17:39.428627  4296 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.829s	user 1.816s	sys 0.140s
I20260812 06:17:39.492784  4296 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.064s	user 0.001s	sys 0.000s
I20260812 06:17:39.493460  4296 tablet_server.cc:179] TabletServer@127.4.50.1:0 shutting down...
I20260812 06:17:39.546677  4427 maintenance_manager.cc:643] P ec1884233b374114abf220c4d24fbc05: MajorDeltaCompactionOp(3b5ccc4454bb4e1cb9e22fae9cf14ebc) complete. Timing: real 0.137s	user 0.093s	sys 0.044s Metrics: {"cfile_cache_miss":531,"cfile_cache_miss_bytes":24774572,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":819,"lbm_read_time_us":9718,"lbm_reads_lt_1ms":563,"lbm_write_time_us":24708,"lbm_writes_lt_1ms":543,"mutex_wait_us":297,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6016,"update_count":2500}
I20260812 06:17:39.547386  4296 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:39.547778  4296 tablet_replica.cc:333] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc P ec1884233b374114abf220c4d24fbc05: stopping tablet replica
I20260812 06:17:39.548020  4296 raft_consensus.cc:2243] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc P ec1884233b374114abf220c4d24fbc05 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:39.548271  4296 raft_consensus.cc:2272] T 3b5ccc4454bb4e1cb9e22fae9cf14ebc P ec1884233b374114abf220c4d24fbc05 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:39.565184  4296 tablet_server.cc:196] TabletServer@127.4.50.1:0 shutdown complete.
I20260812 06:17:39.592443  4296 master.cc:562] Master@127.4.50.62:37273 shutting down...
I20260812 06:17:39.596104  4296 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 37db1145e74a4a69b26c5115de5b14fe [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:39.596295  4296 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 37db1145e74a4a69b26c5115de5b14fe [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:39.596388  4296 tablet_replica.cc:333] T 00000000000000000000000000000000 P 37db1145e74a4a69b26c5115de5b14fe: stopping tablet replica
I20260812 06:17:39.608497  4296 master.cc:584] Master@127.4.50.62:37273 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5371 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:39.710753  4296 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.4.50.62:39711
I20260812 06:17:39.711227  4296 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:39.713312  4538 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:39.713474  4296 server_base.cc:1061] running on GCE node
W20260812 06:17:39.713446  4540 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:39.713456  4542 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:39.713863  4296 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:39.713924  4296 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:39.713941  4296 hybrid_clock.cc:648] HybridClock initialized: now 1786515459713941 us; error 0 us; skew 500 ppm
I20260812 06:17:39.714928  4296 webserver.cc:533] Webserver started at http://127.4.50.62:40741/ using document root <none> and password file <none>
I20260812 06:17:39.715127  4296 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:39.715197  4296 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:39.715291  4296 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:39.715718  4296 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454317672-4296-0/minicluster-data/master-0-root/instance:
uuid: "880a2eccecf743798ce14497daa85a43"
format_stamp: "Formatted at 2026-08-12 06:17:39 on dist-test-slave-7c35"
I20260812 06:17:39.717510  4296 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:39.718542  4547 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:39.718809  4296 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:39.718918  4296 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454317672-4296-0/minicluster-data/master-0-root
uuid: "880a2eccecf743798ce14497daa85a43"
format_stamp: "Formatted at 2026-08-12 06:17:39 on dist-test-slave-7c35"
I20260812 06:17:39.719003  4296 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454317672-4296-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454317672-4296-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454317672-4296-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:39.730839  4296 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:39.731302  4296 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:39.735821  4296 rpc_server.cc:307] RPC server started. Bound to: 127.4.50.62:39711
I20260812 06:17:39.739847  4610 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.4.50.62:39711 every 8 connection(s)
I20260812 06:17:39.740293  4611 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:39.742020  4611 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 880a2eccecf743798ce14497daa85a43: Bootstrap starting.
I20260812 06:17:39.742789  4611 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 880a2eccecf743798ce14497daa85a43: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:39.743796  4611 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 880a2eccecf743798ce14497daa85a43: No bootstrap required, opened a new log
I20260812 06:17:39.744216  4611 raft_consensus.cc:359] T 00000000000000000000000000000000 P 880a2eccecf743798ce14497daa85a43 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "880a2eccecf743798ce14497daa85a43" member_type: VOTER }
I20260812 06:17:39.744302  4611 raft_consensus.cc:385] T 00000000000000000000000000000000 P 880a2eccecf743798ce14497daa85a43 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:39.744324  4611 raft_consensus.cc:740] T 00000000000000000000000000000000 P 880a2eccecf743798ce14497daa85a43 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 880a2eccecf743798ce14497daa85a43, State: Initialized, Role: FOLLOWER
I20260812 06:17:39.744475  4611 consensus_queue.cc:260] T 00000000000000000000000000000000 P 880a2eccecf743798ce14497daa85a43 [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: "880a2eccecf743798ce14497daa85a43" member_type: VOTER }
I20260812 06:17:39.744546  4611 raft_consensus.cc:399] T 00000000000000000000000000000000 P 880a2eccecf743798ce14497daa85a43 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:39.744606  4611 raft_consensus.cc:493] T 00000000000000000000000000000000 P 880a2eccecf743798ce14497daa85a43 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:39.744668  4611 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 880a2eccecf743798ce14497daa85a43 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:39.745352  4611 raft_consensus.cc:515] T 00000000000000000000000000000000 P 880a2eccecf743798ce14497daa85a43 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "880a2eccecf743798ce14497daa85a43" member_type: VOTER }
I20260812 06:17:39.745488  4611 leader_election.cc:304] T 00000000000000000000000000000000 P 880a2eccecf743798ce14497daa85a43 [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: 880a2eccecf743798ce14497daa85a43; no voters: 
I20260812 06:17:39.745716  4611 leader_election.cc:290] T 00000000000000000000000000000000 P 880a2eccecf743798ce14497daa85a43 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:39.745820  4615 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 880a2eccecf743798ce14497daa85a43 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:39.746035  4615 raft_consensus.cc:697] T 00000000000000000000000000000000 P 880a2eccecf743798ce14497daa85a43 [term 1 LEADER]: Becoming Leader. State: Replica: 880a2eccecf743798ce14497daa85a43, State: Running, Role: LEADER
I20260812 06:17:39.746155  4611 sys_catalog.cc:565] T 00000000000000000000000000000000 P 880a2eccecf743798ce14497daa85a43 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:39.746189  4615 consensus_queue.cc:237] T 00000000000000000000000000000000 P 880a2eccecf743798ce14497daa85a43 [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: "880a2eccecf743798ce14497daa85a43" member_type: VOTER }
I20260812 06:17:39.746639  4616 sys_catalog.cc:455] T 00000000000000000000000000000000 P 880a2eccecf743798ce14497daa85a43 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "880a2eccecf743798ce14497daa85a43" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "880a2eccecf743798ce14497daa85a43" member_type: VOTER } }
I20260812 06:17:39.746665  4618 sys_catalog.cc:455] T 00000000000000000000000000000000 P 880a2eccecf743798ce14497daa85a43 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 880a2eccecf743798ce14497daa85a43. Latest consensus state: current_term: 1 leader_uuid: "880a2eccecf743798ce14497daa85a43" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "880a2eccecf743798ce14497daa85a43" member_type: VOTER } }
I20260812 06:17:39.746731  4616 sys_catalog.cc:458] T 00000000000000000000000000000000 P 880a2eccecf743798ce14497daa85a43 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:39.746767  4618 sys_catalog.cc:458] T 00000000000000000000000000000000 P 880a2eccecf743798ce14497daa85a43 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:39.748006  4296 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:17:39.748442  4637 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 880a2eccecf743798ce14497daa85a43: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:17:39.748512  4637 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:17:39.748585  4623 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:39.749176  4623 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:39.750910  4623 catalog_manager.cc:1383] Generated new cluster ID: 9df101eeeaec45bfa0670b74cb556fed
I20260812 06:17:39.750986  4623 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:39.766541  4623 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:39.767135  4623 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:39.776046  4623 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 880a2eccecf743798ce14497daa85a43: Generated new TSK 0
I20260812 06:17:39.776234  4623 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:39.780105  4296 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:39.782027  4643 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:39.782040  4641 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:39.782146  4639 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:39.782346  4296 server_base.cc:1061] running on GCE node
I20260812 06:17:39.782518  4296 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:39.782555  4296 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:39.782570  4296 hybrid_clock.cc:648] HybridClock initialized: now 1786515459782570 us; error 0 us; skew 500 ppm
I20260812 06:17:39.783545  4296 webserver.cc:533] Webserver started at http://127.4.50.1:44789/ using document root <none> and password file <none>
I20260812 06:17:39.783707  4296 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:39.783762  4296 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:39.783856  4296 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:39.784233  4296 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454317672-4296-0/minicluster-data/ts-0-root/instance:
uuid: "e3f1363d13a7451182f48bced889d847"
format_stamp: "Formatted at 2026-08-12 06:17:39 on dist-test-slave-7c35"
I20260812 06:17:39.785722  4296 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:17:39.786715  4648 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:39.787030  4296 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:17:39.787118  4296 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454317672-4296-0/minicluster-data/ts-0-root
uuid: "e3f1363d13a7451182f48bced889d847"
format_stamp: "Formatted at 2026-08-12 06:17:39 on dist-test-slave-7c35"
I20260812 06:17:39.787206  4296 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454317672-4296-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454317672-4296-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454317672-4296-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:39.800544  4296 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:39.800863  4296 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:39.801146  4296 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:39.801586  4296 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:39.801645  4296 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:39.801707  4296 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:39.801759  4296 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:39.805990  4296 rpc_server.cc:307] RPC server started. Bound to: 127.4.50.1:42363
I20260812 06:17:39.806036  4738 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.4.50.1:42363 every 8 connection(s)
I20260812 06:17:39.815471  4739 heartbeater.cc:344] Connected to a master server at 127.4.50.62:39711
I20260812 06:17:39.815599  4739 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:39.815812  4739 heartbeater.cc:507] Master 127.4.50.62:39711 requested a full tablet report, sending...
I20260812 06:17:39.816432  4568 ts_manager.cc:194] Registered new tserver with Master: e3f1363d13a7451182f48bced889d847 (127.4.50.1:42363)
I20260812 06:17:39.817188  4568 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:46678
I20260812 06:17:39.817505  4296 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011060631s
I20260812 06:17:39.824290  4568 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:46682:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:17:39.832703  4689 tablet_service.cc:1511] Processing CreateTablet for tablet a637810f8d9045099f2f6dbf1c4046f7 (DEFAULT_TABLE table=heavy-update-compaction-test [id=0430c8942024453c9332b7caf034dae0]), partition=
I20260812 06:17:39.832973  4689 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet a637810f8d9045099f2f6dbf1c4046f7. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:39.834975  4759 tablet_bootstrap.cc:492] T a637810f8d9045099f2f6dbf1c4046f7 P e3f1363d13a7451182f48bced889d847: Bootstrap starting.
I20260812 06:17:39.836006  4759 tablet_bootstrap.cc:654] T a637810f8d9045099f2f6dbf1c4046f7 P e3f1363d13a7451182f48bced889d847: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:39.836930  4759 tablet_bootstrap.cc:492] T a637810f8d9045099f2f6dbf1c4046f7 P e3f1363d13a7451182f48bced889d847: No bootstrap required, opened a new log
I20260812 06:17:39.837000  4759 ts_tablet_manager.cc:1403] T a637810f8d9045099f2f6dbf1c4046f7 P e3f1363d13a7451182f48bced889d847: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:17:39.837393  4759 raft_consensus.cc:359] T a637810f8d9045099f2f6dbf1c4046f7 P e3f1363d13a7451182f48bced889d847 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e3f1363d13a7451182f48bced889d847" member_type: VOTER last_known_addr { host: "127.4.50.1" port: 42363 } }
I20260812 06:17:39.837507  4759 raft_consensus.cc:385] T a637810f8d9045099f2f6dbf1c4046f7 P e3f1363d13a7451182f48bced889d847 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:39.837532  4759 raft_consensus.cc:740] T a637810f8d9045099f2f6dbf1c4046f7 P e3f1363d13a7451182f48bced889d847 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: e3f1363d13a7451182f48bced889d847, State: Initialized, Role: FOLLOWER
I20260812 06:17:39.837673  4759 consensus_queue.cc:260] T a637810f8d9045099f2f6dbf1c4046f7 P e3f1363d13a7451182f48bced889d847 [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: "e3f1363d13a7451182f48bced889d847" member_type: VOTER last_known_addr { host: "127.4.50.1" port: 42363 } }
I20260812 06:17:39.837762  4759 raft_consensus.cc:399] T a637810f8d9045099f2f6dbf1c4046f7 P e3f1363d13a7451182f48bced889d847 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:39.837788  4759 raft_consensus.cc:493] T a637810f8d9045099f2f6dbf1c4046f7 P e3f1363d13a7451182f48bced889d847 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:39.837824  4759 raft_consensus.cc:3060] T a637810f8d9045099f2f6dbf1c4046f7 P e3f1363d13a7451182f48bced889d847 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:39.838802  4759 raft_consensus.cc:515] T a637810f8d9045099f2f6dbf1c4046f7 P e3f1363d13a7451182f48bced889d847 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e3f1363d13a7451182f48bced889d847" member_type: VOTER last_known_addr { host: "127.4.50.1" port: 42363 } }
I20260812 06:17:39.838984  4759 leader_election.cc:304] T a637810f8d9045099f2f6dbf1c4046f7 P e3f1363d13a7451182f48bced889d847 [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: e3f1363d13a7451182f48bced889d847; no voters: 
I20260812 06:17:39.839126  4759 leader_election.cc:290] T a637810f8d9045099f2f6dbf1c4046f7 P e3f1363d13a7451182f48bced889d847 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:39.839279  4762 raft_consensus.cc:2804] T a637810f8d9045099f2f6dbf1c4046f7 P e3f1363d13a7451182f48bced889d847 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:39.839462  4739 heartbeater.cc:499] Master 127.4.50.62:39711 was elected leader, sending a full tablet report...
I20260812 06:17:39.839496  4762 raft_consensus.cc:697] T a637810f8d9045099f2f6dbf1c4046f7 P e3f1363d13a7451182f48bced889d847 [term 1 LEADER]: Becoming Leader. State: Replica: e3f1363d13a7451182f48bced889d847, State: Running, Role: LEADER
I20260812 06:17:39.839643  4762 consensus_queue.cc:237] T a637810f8d9045099f2f6dbf1c4046f7 P e3f1363d13a7451182f48bced889d847 [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: "e3f1363d13a7451182f48bced889d847" member_type: VOTER last_known_addr { host: "127.4.50.1" port: 42363 } }
I20260812 06:17:39.839715  4759 ts_tablet_manager.cc:1434] T a637810f8d9045099f2f6dbf1c4046f7 P e3f1363d13a7451182f48bced889d847: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:17:39.840972  4568 catalog_manager.cc:5719] T a637810f8d9045099f2f6dbf1c4046f7 P e3f1363d13a7451182f48bced889d847 reported cstate change: term changed from 0 to 1, leader changed from <none> to e3f1363d13a7451182f48bced889d847 (127.4.50.1). New cstate: current_term: 1 leader_uuid: "e3f1363d13a7451182f48bced889d847" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e3f1363d13a7451182f48bced889d847" member_type: VOTER last_known_addr { host: "127.4.50.1" port: 42363 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:39.893751  4296 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.049s	user 0.007s	sys 0.016s
I20260812 06:17:40.056844  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling FlushMRSOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=23.023690
I20260812 06:17:40.219274  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: FlushMRSOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.162s	user 0.095s	sys 0.067s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":160,"dirs.run_cpu_time_us":179,"dirs.run_wall_time_us":1151,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40535,"lbm_writes_lt_1ms":857,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":1500}
I20260812 06:17:40.220013  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling LogGCOp(a637810f8d9045099f2f6dbf1c4046f7): free 20290830 bytes of WAL
I20260812 06:17:40.220237  4657 log_reader.cc:385] T a637810f8d9045099f2f6dbf1c4046f7: removed 2 log segments from log reader
I20260812 06:17:40.220350  4657 log.cc:1079] T a637810f8d9045099f2f6dbf1c4046f7 P e3f1363d13a7451182f48bced889d847: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/a637810f8d9045099f2f6dbf1c4046f7/wal-000000001 (ops 1-6)
I20260812 06:17:40.220439  4657 log.cc:1079] T a637810f8d9045099f2f6dbf1c4046f7 P e3f1363d13a7451182f48bced889d847: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/a637810f8d9045099f2f6dbf1c4046f7/wal-000000002 (ops 7-10)
I20260812 06:17:40.224511  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: LogGCOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.004s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:17:40.224831  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=2.188937
I20260812 06:17:40.252575  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.028s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5535,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:40.253044  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=2.188937
I20260812 06:17:40.263849  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4091,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:40.264302  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling UndoDeltaBlockGCOp(a637810f8d9045099f2f6dbf1c4046f7): 20513815 bytes on disk
I20260812 06:17:40.264730  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: UndoDeltaBlockGCOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4}
I20260812 06:17:40.265130  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling MajorDeltaCompactionOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=1.000000
I20260812 06:17:40.455132  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: MajorDeltaCompactionOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.190s	user 0.120s	sys 0.069s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815802,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":904,"lbm_read_time_us":13576,"lbm_reads_lt_1ms":569,"lbm_write_time_us":29730,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5248,"thread_start_us":382,"threads_started":5,"update_count":2500}
I20260812 06:17:40.455899  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=14.095187
I20260812 06:17:40.510583  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.054s	user 0.029s	sys 0.022s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25002,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:40.511143  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=2.188937
I20260812 06:17:40.526099  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5643,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:40.526712  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling MajorDeltaCompactionOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=1.000000
I20260812 06:17:40.713001  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: MajorDeltaCompactionOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.186s	user 0.122s	sys 0.058s 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":1257,"lbm_read_time_us":12552,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31789,"lbm_writes_lt_1ms":543,"mutex_wait_us":333,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15488,"update_count":2500}
I20260812 06:17:40.713776  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=15.087375
I20260812 06:17:40.783275  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.069s	user 0.038s	sys 0.023s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":28202,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:17:40.783826  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=2.188937
I20260812 06:17:40.794514  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4184710,"delete_count":0,"lbm_write_time_us":4338,"lbm_writes_lt_1ms":105,"reinsert_count":0,"update_count":510}
I20260812 06:17:40.794951  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=2.188937
I20260812 06:17:40.803741  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.009s	user 0.006s	sys 0.002s Metrics: {"bytes_written":3610355,"delete_count":0,"lbm_write_time_us":3432,"lbm_writes_lt_1ms":91,"reinsert_count":0,"update_count":440}
I20260812 06:17:40.804085  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling MajorDeltaCompactionOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=1.000000
I20260812 06:17:41.010782  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: MajorDeltaCompactionOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.207s	user 0.126s	sys 0.069s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918202,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":497,"lbm_read_time_us":13112,"lbm_reads_lt_1ms":673,"lbm_write_time_us":33416,"lbm_writes_lt_1ms":643,"mutex_wait_us":21,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":3000}
I20260812 06:17:41.011418  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=18.063937
I20260812 06:17:41.074251  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.063s	user 0.032s	sys 0.019s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":24486,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:41.074741  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=2.188937
I20260812 06:17:41.091042  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.016s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6323,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:41.091611  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling MajorDeltaCompactionOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=1.000000
I20260812 06:17:41.311144  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: MajorDeltaCompactionOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.219s	user 0.154s	sys 0.056s 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":367,"lbm_read_time_us":15282,"lbm_reads_lt_1ms":672,"lbm_write_time_us":36127,"lbm_writes_lt_1ms":643,"mutex_wait_us":38,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3584,"update_count":3000}
I20260812 06:17:41.311955  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=18.063937
I20260812 06:17:41.379617  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.067s	user 0.035s	sys 0.022s Metrics: {"bytes_written":20512320,"delete_count":0,"lbm_write_time_us":25711,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:41.380196  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=2.188937
I20260812 06:17:41.391636  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.011s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4115,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:41.392096  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling FlushMRSOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=1.000000
I20260812 06:17:41.422700  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: FlushMRSOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.030s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":52,"dirs.run_cpu_time_us":240,"dirs.run_wall_time_us":1468,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1448,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:41.423255  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling LogGCOp(a637810f8d9045099f2f6dbf1c4046f7): free 117302565 bytes of WAL
I20260812 06:17:41.423460  4657 log_reader.cc:385] T a637810f8d9045099f2f6dbf1c4046f7: removed 12 log segments from log reader
I20260812 06:17:41.423514  4657 log.cc:1079] T a637810f8d9045099f2f6dbf1c4046f7 P e3f1363d13a7451182f48bced889d847: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/a637810f8d9045099f2f6dbf1c4046f7/wal-000000003 (ops 11-15)
I20260812 06:17:41.423559  4657 log.cc:1079] T a637810f8d9045099f2f6dbf1c4046f7 P e3f1363d13a7451182f48bced889d847: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/a637810f8d9045099f2f6dbf1c4046f7/wal-000000004 (ops 16-20)
I20260812 06:17:41.423612  4657 log.cc:1079] T a637810f8d9045099f2f6dbf1c4046f7 P e3f1363d13a7451182f48bced889d847: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/a637810f8d9045099f2f6dbf1c4046f7/wal-000000005 (ops 21-25)
I20260812 06:17:41.423650  4657 log.cc:1079] T a637810f8d9045099f2f6dbf1c4046f7 P e3f1363d13a7451182f48bced889d847: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/a637810f8d9045099f2f6dbf1c4046f7/wal-000000006 (ops 26-30)
I20260812 06:17:41.423683  4657 log.cc:1079] T a637810f8d9045099f2f6dbf1c4046f7 P e3f1363d13a7451182f48bced889d847: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/a637810f8d9045099f2f6dbf1c4046f7/wal-000000007 (ops 31-35)
I20260812 06:17:41.423720  4657 log.cc:1079] T a637810f8d9045099f2f6dbf1c4046f7 P e3f1363d13a7451182f48bced889d847: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/a637810f8d9045099f2f6dbf1c4046f7/wal-000000008 (ops 36-40)
I20260812 06:17:41.423755  4657 log.cc:1079] T a637810f8d9045099f2f6dbf1c4046f7 P e3f1363d13a7451182f48bced889d847: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/a637810f8d9045099f2f6dbf1c4046f7/wal-000000009 (ops 41-44)
I20260812 06:17:41.423791  4657 log.cc:1079] T a637810f8d9045099f2f6dbf1c4046f7 P e3f1363d13a7451182f48bced889d847: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/a637810f8d9045099f2f6dbf1c4046f7/wal-000000010 (ops 45-49)
I20260812 06:17:41.423827  4657 log.cc:1079] T a637810f8d9045099f2f6dbf1c4046f7 P e3f1363d13a7451182f48bced889d847: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/a637810f8d9045099f2f6dbf1c4046f7/wal-000000011 (ops 50-54)
I20260812 06:17:41.423882  4657 log.cc:1079] T a637810f8d9045099f2f6dbf1c4046f7 P e3f1363d13a7451182f48bced889d847: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/a637810f8d9045099f2f6dbf1c4046f7/wal-000000012 (ops 55-58)
I20260812 06:17:41.423915  4657 log.cc:1079] T a637810f8d9045099f2f6dbf1c4046f7 P e3f1363d13a7451182f48bced889d847: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/a637810f8d9045099f2f6dbf1c4046f7/wal-000000013 (ops 59-63)
I20260812 06:17:41.423954  4657 log.cc:1079] T a637810f8d9045099f2f6dbf1c4046f7 P e3f1363d13a7451182f48bced889d847: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/a637810f8d9045099f2f6dbf1c4046f7/wal-000000014 (ops 64-68)
I20260812 06:17:41.449126  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: LogGCOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.026s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:17:41.449533  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling UndoDeltaBlockGCOp(a637810f8d9045099f2f6dbf1c4046f7): 447 bytes on disk
I20260812 06:17:41.449918  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: UndoDeltaBlockGCOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4}
I20260812 06:17:41.450449  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=3.181125
I20260812 06:17:41.469470  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.019s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":6659,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:41.469842  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=2.188937
I20260812 06:17:41.478993  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.009s	user 0.001s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3692,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:41.479344  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling MajorDeltaCompactionOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=1.000000
I20260812 06:17:41.715312  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: MajorDeltaCompactionOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.236s	user 0.119s	sys 0.116s Metrics: {"cfile_cache_miss":834,"cfile_cache_miss_bytes":37123153,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":134,"lbm_read_time_us":16179,"lbm_reads_lt_1ms":874,"lbm_write_time_us":44574,"lbm_writes_lt_1ms":843,"mutex_wait_us":70,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":73,"threads_started":1,"update_count":4000}
I20260812 06:17:41.716014  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=18.063937
I20260812 06:17:41.781036  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.065s	user 0.023s	sys 0.024s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":22105,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:41.781657  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=2.188937
I20260812 06:17:41.800064  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.018s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5813,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:41.800601  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling MajorDeltaCompactionOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=1.000000
I20260812 06:17:41.969990  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: MajorDeltaCompactionOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.169s	user 0.129s	sys 0.040s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918097,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":327,"lbm_read_time_us":11784,"lbm_reads_lt_1ms":664,"lbm_write_time_us":35898,"lbm_writes_lt_1ms":643,"mutex_wait_us":44,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4992,"update_count":3000}
I20260812 06:17:41.970723  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=14.095187
I20260812 06:17:42.016130  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.045s	user 0.015s	sys 0.025s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18213,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:42.016593  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=2.188937
I20260812 06:17:42.027828  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4271,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:42.028214  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling MajorDeltaCompactionOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=1.000000
I20260812 06:17:42.190376  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: MajorDeltaCompactionOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.162s	user 0.107s	sys 0.044s 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":666,"lbm_read_time_us":9901,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28383,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13952,"update_count":2500}
I20260812 06:17:42.191078  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=14.095187
I20260812 06:17:42.252525  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.061s	user 0.023s	sys 0.025s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22287,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:42.253016  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=2.188937
I20260812 06:17:42.263144  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3837,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:42.263541  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling MajorDeltaCompactionOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=1.000000
I20260812 06:17:42.443213  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: MajorDeltaCompactionOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.179s	user 0.128s	sys 0.047s 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":365,"lbm_read_time_us":12249,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32001,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:42.443918  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=14.095187
I20260812 06:17:42.493489  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.049s	user 0.023s	sys 0.024s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":21554,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:42.493942  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=2.188937
I20260812 06:17:42.504665  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4003,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:42.505206  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling MajorDeltaCompactionOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=1.000000
I20260812 06:17:42.681080  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: MajorDeltaCompactionOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.176s	user 0.118s	sys 0.051s 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":759,"lbm_read_time_us":12300,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27288,"lbm_writes_lt_1ms":543,"mutex_wait_us":51,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2500}
I20260812 06:17:42.681708  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=14.095187
I20260812 06:17:42.743458  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.062s	user 0.042s	sys 0.018s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23086,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:42.744009  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=2.188937
I20260812 06:17:42.755868  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.012s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4702,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:42.756342  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling FlushMRSOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=1.000000
I20260812 06:17:42.798801  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: FlushMRSOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.042s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":86,"dirs.run_cpu_time_us":242,"dirs.run_wall_time_us":1548,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1530,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:42.799544  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling LogGCOp(a637810f8d9045099f2f6dbf1c4046f7): free 120100272 bytes of WAL
I20260812 06:17:42.799791  4657 log_reader.cc:385] T a637810f8d9045099f2f6dbf1c4046f7: removed 12 log segments from log reader
I20260812 06:17:42.799840  4657 log.cc:1079] T a637810f8d9045099f2f6dbf1c4046f7 P e3f1363d13a7451182f48bced889d847: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/a637810f8d9045099f2f6dbf1c4046f7/wal-000000015 (ops 69-72)
I20260812 06:17:42.799894  4657 log.cc:1079] T a637810f8d9045099f2f6dbf1c4046f7 P e3f1363d13a7451182f48bced889d847: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/a637810f8d9045099f2f6dbf1c4046f7/wal-000000016 (ops 73-77)
I20260812 06:17:42.799947  4657 log.cc:1079] T a637810f8d9045099f2f6dbf1c4046f7 P e3f1363d13a7451182f48bced889d847: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/a637810f8d9045099f2f6dbf1c4046f7/wal-000000017 (ops 78-82)
I20260812 06:17:42.799991  4657 log.cc:1079] T a637810f8d9045099f2f6dbf1c4046f7 P e3f1363d13a7451182f48bced889d847: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/a637810f8d9045099f2f6dbf1c4046f7/wal-000000018 (ops 83-86)
I20260812 06:17:42.800058  4657 log.cc:1079] T a637810f8d9045099f2f6dbf1c4046f7 P e3f1363d13a7451182f48bced889d847: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/a637810f8d9045099f2f6dbf1c4046f7/wal-000000019 (ops 87-91)
I20260812 06:17:42.800105  4657 log.cc:1079] T a637810f8d9045099f2f6dbf1c4046f7 P e3f1363d13a7451182f48bced889d847: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/a637810f8d9045099f2f6dbf1c4046f7/wal-000000020 (ops 92-96)
I20260812 06:17:42.800174  4657 log.cc:1079] T a637810f8d9045099f2f6dbf1c4046f7 P e3f1363d13a7451182f48bced889d847: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/a637810f8d9045099f2f6dbf1c4046f7/wal-000000021 (ops 97-101)
I20260812 06:17:42.800220  4657 log.cc:1079] T a637810f8d9045099f2f6dbf1c4046f7 P e3f1363d13a7451182f48bced889d847: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/a637810f8d9045099f2f6dbf1c4046f7/wal-000000022 (ops 102-106)
I20260812 06:17:42.800263  4657 log.cc:1079] T a637810f8d9045099f2f6dbf1c4046f7 P e3f1363d13a7451182f48bced889d847: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/a637810f8d9045099f2f6dbf1c4046f7/wal-000000023 (ops 107-111)
I20260812 06:17:42.800307  4657 log.cc:1079] T a637810f8d9045099f2f6dbf1c4046f7 P e3f1363d13a7451182f48bced889d847: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/a637810f8d9045099f2f6dbf1c4046f7/wal-000000024 (ops 112-116)
I20260812 06:17:42.800351  4657 log.cc:1079] T a637810f8d9045099f2f6dbf1c4046f7 P e3f1363d13a7451182f48bced889d847: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/a637810f8d9045099f2f6dbf1c4046f7/wal-000000025 (ops 117-120)
I20260812 06:17:42.800403  4657 log.cc:1079] T a637810f8d9045099f2f6dbf1c4046f7 P e3f1363d13a7451182f48bced889d847: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/a637810f8d9045099f2f6dbf1c4046f7/wal-000000026 (ops 121-125)
I20260812 06:17:42.824684  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: LogGCOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.025s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:17:42.825171  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=2.188937
I20260812 06:17:42.844856  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.019s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5607,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:42.845319  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling UndoDeltaBlockGCOp(a637810f8d9045099f2f6dbf1c4046f7): 446 bytes on disk
I20260812 06:17:42.845737  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: UndoDeltaBlockGCOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4}
I20260812 06:17:42.846297  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=2.188937
I20260812 06:17:42.859608  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.013s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4783,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:42.860249  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling MajorDeltaCompactionOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=1.000000
I20260812 06:17:43.102125  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: MajorDeltaCompactionOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.242s	user 0.135s	sys 0.106s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020745,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":916,"lbm_read_time_us":17018,"lbm_reads_lt_1ms":774,"lbm_write_time_us":43809,"lbm_writes_lt_1ms":743,"mutex_wait_us":353,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1408,"thread_start_us":73,"threads_started":1,"update_count":3500}
I20260812 06:17:43.102769  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=18.063937
I20260812 06:17:43.163883  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.061s	user 0.034s	sys 0.025s Metrics: {"bytes_written":20512319,"delete_count":0,"lbm_write_time_us":27168,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:17:43.164649  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=2.188937
I20260812 06:17:43.187122  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.022s	user 0.002s	sys 0.011s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5475,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:43.187526  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=2.188937
I20260812 06:17:43.201481  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5463,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:43.201943  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling MajorDeltaCompactionOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=1.000000
I20260812 06:17:43.387159  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: MajorDeltaCompactionOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.185s	user 0.144s	sys 0.040s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":33020631,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":644,"lbm_read_time_us":12862,"lbm_reads_lt_1ms":773,"lbm_write_time_us":39940,"lbm_writes_lt_1ms":743,"mutex_wait_us":357,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":3328,"update_count":3500}
I20260812 06:17:43.387912  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=14.095187
I20260812 06:17:43.433116  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.045s	user 0.026s	sys 0.016s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":19518,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:43.433718  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=2.188937
I20260812 06:17:43.450467  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.017s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5753,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:43.451114  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling MajorDeltaCompactionOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=1.000000
I20260812 06:17:43.600081  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: MajorDeltaCompactionOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.149s	user 0.109s	sys 0.033s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":290,"lbm_read_time_us":10079,"lbm_reads_lt_1ms":564,"lbm_write_time_us":27619,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3328,"update_count":2500}
I20260812 06:17:43.600713  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=14.095187
I20260812 06:17:43.660297  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.059s	user 0.031s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":26589,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:43.660749  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=2.188937
I20260812 06:17:43.670799  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3835,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:43.671438  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling MajorDeltaCompactionOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=1.000000
I20260812 06:17:43.843760  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: MajorDeltaCompactionOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.172s	user 0.113s	sys 0.048s 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":201,"lbm_read_time_us":10478,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29467,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12544,"update_count":2500}
I20260812 06:17:43.844558  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=14.095187
I20260812 06:17:43.896270  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.052s	user 0.027s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19683,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:43.896818  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=2.188937
I20260812 06:17:43.911614  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.015s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5617,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:43.912386  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling MajorDeltaCompactionOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=1.000000
I20260812 06:17:44.083909  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: MajorDeltaCompactionOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.171s	user 0.108s	sys 0.056s 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":586,"lbm_read_time_us":12392,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29310,"lbm_writes_lt_1ms":543,"mutex_wait_us":46,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3712,"update_count":2500}
I20260812 06:17:44.084527  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=14.095187
I20260812 06:17:44.141949  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.057s	user 0.027s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23595,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:44.142446  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=2.188937
I20260812 06:17:44.154004  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4181,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:44.154444  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling FlushMRSOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=1.000000
I20260812 06:17:44.184604  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: FlushMRSOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.030s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1193505,"cfile_init":1,"dirs.queue_time_us":72,"dirs.run_cpu_time_us":218,"dirs.run_wall_time_us":1490,"drs_written":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1491,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:44.185278  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling LogGCOp(a637810f8d9045099f2f6dbf1c4046f7): free 112239539 bytes of WAL
I20260812 06:17:44.185549  4657 log_reader.cc:385] T a637810f8d9045099f2f6dbf1c4046f7: removed 11 log segments from log reader
I20260812 06:17:44.185609  4657 log.cc:1079] T a637810f8d9045099f2f6dbf1c4046f7 P e3f1363d13a7451182f48bced889d847: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/a637810f8d9045099f2f6dbf1c4046f7/wal-000000027 (ops 126-130)
I20260812 06:17:44.185657  4657 log.cc:1079] T a637810f8d9045099f2f6dbf1c4046f7 P e3f1363d13a7451182f48bced889d847: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/a637810f8d9045099f2f6dbf1c4046f7/wal-000000028 (ops 131-134)
I20260812 06:17:44.185707  4657 log.cc:1079] T a637810f8d9045099f2f6dbf1c4046f7 P e3f1363d13a7451182f48bced889d847: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/a637810f8d9045099f2f6dbf1c4046f7/wal-000000029 (ops 135-139)
I20260812 06:17:44.185730  4657 log.cc:1079] T a637810f8d9045099f2f6dbf1c4046f7 P e3f1363d13a7451182f48bced889d847: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/a637810f8d9045099f2f6dbf1c4046f7/wal-000000030 (ops 140-144)
I20260812 06:17:44.185760  4657 log.cc:1079] T a637810f8d9045099f2f6dbf1c4046f7 P e3f1363d13a7451182f48bced889d847: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/a637810f8d9045099f2f6dbf1c4046f7/wal-000000031 (ops 145-149)
I20260812 06:17:44.185787  4657 log.cc:1079] T a637810f8d9045099f2f6dbf1c4046f7 P e3f1363d13a7451182f48bced889d847: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/a637810f8d9045099f2f6dbf1c4046f7/wal-000000032 (ops 150-154)
I20260812 06:17:44.185827  4657 log.cc:1079] T a637810f8d9045099f2f6dbf1c4046f7 P e3f1363d13a7451182f48bced889d847: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/a637810f8d9045099f2f6dbf1c4046f7/wal-000000033 (ops 155-159)
I20260812 06:17:44.185856  4657 log.cc:1079] T a637810f8d9045099f2f6dbf1c4046f7 P e3f1363d13a7451182f48bced889d847: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/a637810f8d9045099f2f6dbf1c4046f7/wal-000000034 (ops 160-164)
I20260812 06:17:44.185904  4657 log.cc:1079] T a637810f8d9045099f2f6dbf1c4046f7 P e3f1363d13a7451182f48bced889d847: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/a637810f8d9045099f2f6dbf1c4046f7/wal-000000035 (ops 165-169)
I20260812 06:17:44.185956  4657 log.cc:1079] T a637810f8d9045099f2f6dbf1c4046f7 P e3f1363d13a7451182f48bced889d847: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/a637810f8d9045099f2f6dbf1c4046f7/wal-000000036 (ops 170-174)
I20260812 06:17:44.185976  4657 log.cc:1079] T a637810f8d9045099f2f6dbf1c4046f7 P e3f1363d13a7451182f48bced889d847: Deleting log segment in path: /tmp/dist-test-taskYIICXG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454317672-4296-0/minicluster-data/ts-0-root/wals/a637810f8d9045099f2f6dbf1c4046f7/wal-000000037 (ops 175-179)
I20260812 06:17:44.211064  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: LogGCOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.026s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:17:44.211668  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling UndoDeltaBlockGCOp(a637810f8d9045099f2f6dbf1c4046f7): 462 bytes on disk
I20260812 06:17:44.212113  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: UndoDeltaBlockGCOp(a637810f8d9045099f2f6dbf1c4046f7) 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:17:44.212780  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=2.188937
I20260812 06:17:44.236410  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.023s	user 0.012s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6010,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:44.236866  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=2.188937
I20260812 06:17:44.247346  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4033,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:44.247738  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling MajorDeltaCompactionOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=1.000000
I20260812 06:17:44.475111  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: MajorDeltaCompactionOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.227s	user 0.150s	sys 0.076s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020744,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":303,"lbm_read_time_us":18672,"lbm_reads_lt_1ms":774,"lbm_write_time_us":39918,"lbm_writes_lt_1ms":743,"mutex_wait_us":71,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":16512,"thread_start_us":78,"threads_started":1,"update_count":3500}
I20260812 06:17:44.475684  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=18.063937
I20260812 06:17:44.533003  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.057s	user 0.047s	sys 0.008s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":25266,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:44.533725  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=2.188937
I20260812 06:17:44.552873  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: FlushDeltaMemStoresOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.019s	user 0.003s	sys 0.013s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6700,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:44.553373  4740 maintenance_manager.cc:419] P e3f1363d13a7451182f48bced889d847: Scheduling MajorDeltaCompactionOp(a637810f8d9045099f2f6dbf1c4046f7): perf score=1.000000
I20260812 06:17:44.616364  4296 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.722s	user 1.783s	sys 0.136s
I20260812 06:17:44.676746  4296 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.060s	user 0.001s	sys 0.000s
I20260812 06:17:44.677275  4296 tablet_server.cc:179] TabletServer@127.4.50.1:0 shutting down...
I20260812 06:17:44.708948  4657 maintenance_manager.cc:643] P e3f1363d13a7451182f48bced889d847: MajorDeltaCompactionOp(a637810f8d9045099f2f6dbf1c4046f7) complete. Timing: real 0.155s	user 0.123s	sys 0.033s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918099,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":382,"lbm_read_time_us":11837,"lbm_reads_lt_1ms":660,"lbm_write_time_us":28688,"lbm_writes_lt_1ms":643,"mutex_wait_us":63,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":3000}
I20260812 06:17:44.709671  4296 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:44.709915  4296 tablet_replica.cc:333] T a637810f8d9045099f2f6dbf1c4046f7 P e3f1363d13a7451182f48bced889d847: stopping tablet replica
I20260812 06:17:44.710058  4296 raft_consensus.cc:2243] T a637810f8d9045099f2f6dbf1c4046f7 P e3f1363d13a7451182f48bced889d847 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:44.710254  4296 raft_consensus.cc:2272] T a637810f8d9045099f2f6dbf1c4046f7 P e3f1363d13a7451182f48bced889d847 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:44.715382  4296 tablet_server.cc:196] TabletServer@127.4.50.1:0 shutdown complete.
I20260812 06:17:44.761487  4296 master.cc:562] Master@127.4.50.62:39711 shutting down...
I20260812 06:17:44.764905  4296 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 880a2eccecf743798ce14497daa85a43 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:44.765090  4296 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 880a2eccecf743798ce14497daa85a43 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:44.765177  4296 tablet_replica.cc:333] T 00000000000000000000000000000000 P 880a2eccecf743798ce14497daa85a43: stopping tablet replica
I20260812 06:17:44.777514  4296 master.cc:584] Master@127.4.50.62:39711 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5165 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10537 ms total)

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