[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:19:40.814265  6936 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.6.198.62:43143
I20260812 06:19:40.815384  6936 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:19:40.816045  6936 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:40.822414  6944 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:40.822504  6941 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:40.822634  6936 server_base.cc:1061] running on GCE node
W20260812 06:19:40.822715  6942 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:40.823163  6936 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:40.823444  6936 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:40.823534  6936 hybrid_clock.cc:648] HybridClock initialized: now 1786515580823531 us; error 0 us; skew 500 ppm
I20260812 06:19:40.825438  6936 webserver.cc:533] Webserver started at http://127.6.198.62:34461/ using document root <none> and password file <none>
I20260812 06:19:40.826071  6936 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:40.826161  6936 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:40.826419  6936 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:40.828044  6936 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580803184-6936-0/minicluster-data/master-0-root/instance:
uuid: "ba11cc38bdc54c5a83ff6e852ad76ace"
format_stamp: "Formatted at 2026-08-12 06:19:40 on dist-test-slave-0kls"
I20260812 06:19:40.831712  6936 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.002s	sys 0.003s
I20260812 06:19:40.834002  6949 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:40.835143  6936 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:40.835290  6936 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580803184-6936-0/minicluster-data/master-0-root
uuid: "ba11cc38bdc54c5a83ff6e852ad76ace"
format_stamp: "Formatted at 2026-08-12 06:19:40 on dist-test-slave-0kls"
I20260812 06:19:40.835402  6936 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580803184-6936-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580803184-6936-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580803184-6936-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:40.859486  6936 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:40.860257  6936 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:19:40.860456  6936 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:40.868705  6936 rpc_server.cc:307] RPC server started. Bound to: 127.6.198.62:43143
I20260812 06:19:40.868703  7008 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.6.198.62:43143 every 8 connection(s)
I20260812 06:19:40.871155  7009 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:40.876866  7009 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P ba11cc38bdc54c5a83ff6e852ad76ace: Bootstrap starting.
I20260812 06:19:40.879299  7009 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P ba11cc38bdc54c5a83ff6e852ad76ace: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:40.880234  7009 log.cc:826] T 00000000000000000000000000000000 P ba11cc38bdc54c5a83ff6e852ad76ace: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:40.882138  7009 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P ba11cc38bdc54c5a83ff6e852ad76ace: No bootstrap required, opened a new log
I20260812 06:19:40.885093  7009 raft_consensus.cc:359] T 00000000000000000000000000000000 P ba11cc38bdc54c5a83ff6e852ad76ace [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ba11cc38bdc54c5a83ff6e852ad76ace" member_type: VOTER }
I20260812 06:19:40.885272  7009 raft_consensus.cc:385] T 00000000000000000000000000000000 P ba11cc38bdc54c5a83ff6e852ad76ace [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:40.885316  7009 raft_consensus.cc:740] T 00000000000000000000000000000000 P ba11cc38bdc54c5a83ff6e852ad76ace [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: ba11cc38bdc54c5a83ff6e852ad76ace, State: Initialized, Role: FOLLOWER
I20260812 06:19:40.886008  7009 consensus_queue.cc:260] T 00000000000000000000000000000000 P ba11cc38bdc54c5a83ff6e852ad76ace [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: "ba11cc38bdc54c5a83ff6e852ad76ace" member_type: VOTER }
I20260812 06:19:40.886193  7009 raft_consensus.cc:399] T 00000000000000000000000000000000 P ba11cc38bdc54c5a83ff6e852ad76ace [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:40.886245  7009 raft_consensus.cc:493] T 00000000000000000000000000000000 P ba11cc38bdc54c5a83ff6e852ad76ace [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:40.886341  7009 raft_consensus.cc:3060] T 00000000000000000000000000000000 P ba11cc38bdc54c5a83ff6e852ad76ace [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:40.887255  7009 raft_consensus.cc:515] T 00000000000000000000000000000000 P ba11cc38bdc54c5a83ff6e852ad76ace [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ba11cc38bdc54c5a83ff6e852ad76ace" member_type: VOTER }
I20260812 06:19:40.887707  7009 leader_election.cc:304] T 00000000000000000000000000000000 P ba11cc38bdc54c5a83ff6e852ad76ace [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: ba11cc38bdc54c5a83ff6e852ad76ace; no voters: 
I20260812 06:19:40.888017  7009 leader_election.cc:290] T 00000000000000000000000000000000 P ba11cc38bdc54c5a83ff6e852ad76ace [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:40.888355  7012 raft_consensus.cc:2804] T 00000000000000000000000000000000 P ba11cc38bdc54c5a83ff6e852ad76ace [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:40.888618  7012 raft_consensus.cc:697] T 00000000000000000000000000000000 P ba11cc38bdc54c5a83ff6e852ad76ace [term 1 LEADER]: Becoming Leader. State: Replica: ba11cc38bdc54c5a83ff6e852ad76ace, State: Running, Role: LEADER
I20260812 06:19:40.889079  7012 consensus_queue.cc:237] T 00000000000000000000000000000000 P ba11cc38bdc54c5a83ff6e852ad76ace [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: "ba11cc38bdc54c5a83ff6e852ad76ace" member_type: VOTER }
I20260812 06:19:40.889309  7009 sys_catalog.cc:565] T 00000000000000000000000000000000 P ba11cc38bdc54c5a83ff6e852ad76ace [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:40.891144  7013 sys_catalog.cc:455] T 00000000000000000000000000000000 P ba11cc38bdc54c5a83ff6e852ad76ace [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "ba11cc38bdc54c5a83ff6e852ad76ace" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ba11cc38bdc54c5a83ff6e852ad76ace" member_type: VOTER } }
I20260812 06:19:40.891196  7014 sys_catalog.cc:455] T 00000000000000000000000000000000 P ba11cc38bdc54c5a83ff6e852ad76ace [sys.catalog]: SysCatalogTable state changed. Reason: New leader ba11cc38bdc54c5a83ff6e852ad76ace. Latest consensus state: current_term: 1 leader_uuid: "ba11cc38bdc54c5a83ff6e852ad76ace" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ba11cc38bdc54c5a83ff6e852ad76ace" member_type: VOTER } }
I20260812 06:19:40.891292  7013 sys_catalog.cc:458] T 00000000000000000000000000000000 P ba11cc38bdc54c5a83ff6e852ad76ace [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:40.891301  7014 sys_catalog.cc:458] T 00000000000000000000000000000000 P ba11cc38bdc54c5a83ff6e852ad76ace [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:40.891654  7023 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:40.891896  6936 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:40.894344  7023 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:40.899564  7023 catalog_manager.cc:1383] Generated new cluster ID: a33057f2435c446f8580bc047cd989d1
I20260812 06:19:40.899654  7023 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:40.913751  7023 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:40.914736  7023 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:40.923827  7023 catalog_manager.cc:6092] T 00000000000000000000000000000000 P ba11cc38bdc54c5a83ff6e852ad76ace: Generated new TSK 0
I20260812 06:19:40.924587  7023 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:40.956700  6936 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:40.960282  7032 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:40.960386  7035 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:40.960227  7033 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:40.960275  6936 server_base.cc:1061] running on GCE node
I20260812 06:19:40.960695  6936 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:40.960740  6936 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:40.960757  6936 hybrid_clock.cc:648] HybridClock initialized: now 1786515580960756 us; error 0 us; skew 500 ppm
I20260812 06:19:40.961836  6936 webserver.cc:533] Webserver started at http://127.6.198.1:35283/ using document root <none> and password file <none>
I20260812 06:19:40.962024  6936 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:40.962075  6936 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:40.962184  6936 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:40.962631  6936 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580803184-6936-0/minicluster-data/ts-0-root/instance:
uuid: "7840f8c7faa24f7d977a446b3f27e11b"
format_stamp: "Formatted at 2026-08-12 06:19:40 on dist-test-slave-0kls"
I20260812 06:19:40.964244  6936 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:40.965289  7040 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:40.965564  6936 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:40.965634  6936 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580803184-6936-0/minicluster-data/ts-0-root
uuid: "7840f8c7faa24f7d977a446b3f27e11b"
format_stamp: "Formatted at 2026-08-12 06:19:40 on dist-test-slave-0kls"
I20260812 06:19:40.965726  6936 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580803184-6936-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580803184-6936-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580803184-6936-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:40.984553  6936 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:40.985061  6936 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:40.985627  6936 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:40.986550  6936 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:40.986601  6936 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:40.986645  6936 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:40.986702  6936 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:40.993911  6936 rpc_server.cc:307] RPC server started. Bound to: 127.6.198.1:37185
I20260812 06:19:40.993938  7108 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.6.198.1:37185 every 8 connection(s)
I20260812 06:19:41.004256  7109 heartbeater.cc:344] Connected to a master server at 127.6.198.62:43143
I20260812 06:19:41.004540  7109 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:41.005028  7109 heartbeater.cc:507] Master 127.6.198.62:43143 requested a full tablet report, sending...
I20260812 06:19:41.006554  6968 ts_manager.cc:194] Registered new tserver with Master: 7840f8c7faa24f7d977a446b3f27e11b (127.6.198.1:37185)
I20260812 06:19:41.006896  6936 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012290787s
I20260812 06:19:41.008111  6968 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:49414
I20260812 06:19:41.017010  6968 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:49418:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:41.031427  7071 tablet_service.cc:1511] Processing CreateTablet for tablet a11b5468485649b9a48a9e3e2c231131 (DEFAULT_TABLE table=heavy-update-compaction-test [id=b81657dbd5604b21863cb3e052788473]), partition=
I20260812 06:19:41.031972  7071 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet a11b5468485649b9a48a9e3e2c231131. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:41.034793  7122 tablet_bootstrap.cc:492] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b: Bootstrap starting.
I20260812 06:19:41.036072  7122 tablet_bootstrap.cc:654] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:41.037461  7122 tablet_bootstrap.cc:492] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b: No bootstrap required, opened a new log
I20260812 06:19:41.037581  7122 ts_tablet_manager.cc:1403] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:19:41.038187  7122 raft_consensus.cc:359] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7840f8c7faa24f7d977a446b3f27e11b" member_type: VOTER last_known_addr { host: "127.6.198.1" port: 37185 } }
I20260812 06:19:41.038341  7122 raft_consensus.cc:385] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:41.038393  7122 raft_consensus.cc:740] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 7840f8c7faa24f7d977a446b3f27e11b, State: Initialized, Role: FOLLOWER
I20260812 06:19:41.038625  7122 consensus_queue.cc:260] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b [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: "7840f8c7faa24f7d977a446b3f27e11b" member_type: VOTER last_known_addr { host: "127.6.198.1" port: 37185 } }
I20260812 06:19:41.038749  7122 raft_consensus.cc:399] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:41.038830  7122 raft_consensus.cc:493] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:41.038888  7122 raft_consensus.cc:3060] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:41.039925  7122 raft_consensus.cc:515] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7840f8c7faa24f7d977a446b3f27e11b" member_type: VOTER last_known_addr { host: "127.6.198.1" port: 37185 } }
I20260812 06:19:41.040093  7122 leader_election.cc:304] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b [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: 7840f8c7faa24f7d977a446b3f27e11b; no voters: 
I20260812 06:19:41.040354  7122 leader_election.cc:290] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:41.040493  7124 raft_consensus.cc:2804] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:41.040727  7122 ts_tablet_manager.cc:1434] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:19:41.040766  7124 raft_consensus.cc:697] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b [term 1 LEADER]: Becoming Leader. State: Replica: 7840f8c7faa24f7d977a446b3f27e11b, State: Running, Role: LEADER
I20260812 06:19:41.040962  7109 heartbeater.cc:499] Master 127.6.198.62:43143 was elected leader, sending a full tablet report...
I20260812 06:19:41.041054  7124 consensus_queue.cc:237] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b [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: "7840f8c7faa24f7d977a446b3f27e11b" member_type: VOTER last_known_addr { host: "127.6.198.1" port: 37185 } }
I20260812 06:19:41.044380  6968 catalog_manager.cc:5719] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b reported cstate change: term changed from 0 to 1, leader changed from <none> to 7840f8c7faa24f7d977a446b3f27e11b (127.6.198.1). New cstate: current_term: 1 leader_uuid: "7840f8c7faa24f7d977a446b3f27e11b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7840f8c7faa24f7d977a446b3f27e11b" member_type: VOTER last_known_addr { host: "127.6.198.1" port: 37185 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:41.113767  6936 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.061s	user 0.027s	sys 0.004s
I20260812 06:19:41.245216  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling FlushMRSOp(a11b5468485649b9a48a9e3e2c231131): perf score=15.086190
I20260812 06:19:41.416488  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: FlushMRSOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.171s	user 0.128s	sys 0.039s Metrics: {"bytes_written":9148636,"cfile_init":1,"compiler_manager_pool.queue_time_us":404,"delete_count":0,"dirs.queue_time_us":69,"dirs.run_cpu_time_us":215,"dirs.run_wall_time_us":1096,"drs_written":1,"lbm_read_time_us":121,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40477,"lbm_writes_lt_1ms":680,"mutex_wait_us":387,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":142208,"thread_start_us":132,"threads_started":1,"update_count":1115}
I20260812 06:19:41.417704  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling LogGCOp(a11b5468485649b9a48a9e3e2c231131): free 20743880 bytes of WAL
I20260812 06:19:41.418076  7045 log_reader.cc:385] T a11b5468485649b9a48a9e3e2c231131: removed 2 log segments from log reader
I20260812 06:19:41.418183  7045 log.cc:1079] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/a11b5468485649b9a48a9e3e2c231131/wal-000000001 (ops 1-6)
I20260812 06:19:41.418264  7045 log.cc:1079] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/a11b5468485649b9a48a9e3e2c231131/wal-000000002 (ops 7-11)
I20260812 06:19:41.424521  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: LogGCOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.007s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:19:41.425181  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling UndoDeltaBlockGCOp(a11b5468485649b9a48a9e3e2c231131): 16411392 bytes on disk
I20260812 06:19:41.425947  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: UndoDeltaBlockGCOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":71,"lbm_reads_lt_1ms":4}
I20260812 06:19:41.426599  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131): perf score=2.188937
I20260812 06:19:41.451865  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.025s	user 0.005s	sys 0.003s Metrics: {"bytes_written":3364209,"delete_count":0,"lbm_write_time_us":3874,"lbm_writes_lt_1ms":85,"reinsert_count":0,"update_count":410}
I20260812 06:19:41.452446  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131): perf score=2.188937
I20260812 06:19:41.467641  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3897534,"delete_count":0,"lbm_write_time_us":5743,"lbm_writes_lt_1ms":98,"reinsert_count":0,"update_count":475}
I20260812 06:19:41.468211  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling MajorDeltaCompactionOp(a11b5468485649b9a48a9e3e2c231131): perf score=1.000000
I20260812 06:19:41.607488  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: MajorDeltaCompactionOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.139s	user 0.108s	sys 0.024s Metrics: {"cfile_cache_miss":433,"cfile_cache_miss_bytes":20672379,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1093,"lbm_read_time_us":8608,"lbm_reads_lt_1ms":469,"lbm_write_time_us":24515,"lbm_writes_lt_1ms":443,"mutex_wait_us":142,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11648,"thread_start_us":359,"threads_started":5,"update_count":2000}
I20260812 06:19:41.608162  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131): perf score=10.126437
I20260812 06:19:41.641067  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.033s	user 0.028s	sys 0.000s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":13490,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:41.641542  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling MajorDeltaCompactionOp(a11b5468485649b9a48a9e3e2c231131): perf score=1.000000
I20260812 06:19:41.754951  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: MajorDeltaCompactionOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.113s	user 0.093s	sys 0.020s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569748,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":288,"lbm_read_time_us":6287,"lbm_reads_lt_1ms":363,"lbm_write_time_us":20401,"lbm_writes_lt_1ms":343,"mutex_wait_us":24,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":13696,"update_count":1500}
I20260812 06:19:41.755645  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131): perf score=10.126437
I20260812 06:19:41.795423  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.039s	user 0.026s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16719,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:41.796082  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling MajorDeltaCompactionOp(a11b5468485649b9a48a9e3e2c231131): perf score=1.000000
I20260812 06:19:41.912912  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: MajorDeltaCompactionOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.117s	user 0.076s	sys 0.040s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569747,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":233,"lbm_read_time_us":6798,"lbm_reads_lt_1ms":367,"lbm_write_time_us":20141,"lbm_writes_lt_1ms":343,"mutex_wait_us":26,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":15616,"update_count":1500}
I20260812 06:19:41.913956  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131): perf score=10.126437
I20260812 06:19:41.955873  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.042s	user 0.031s	sys 0.009s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18928,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:41.956645  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling MajorDeltaCompactionOp(a11b5468485649b9a48a9e3e2c231131): perf score=1.000000
I20260812 06:19:42.067873  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: MajorDeltaCompactionOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.111s	user 0.095s	sys 0.016s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569746,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":347,"lbm_read_time_us":6754,"lbm_reads_lt_1ms":363,"lbm_write_time_us":20338,"lbm_writes_lt_1ms":343,"mutex_wait_us":41,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":11776,"update_count":1500}
I20260812 06:19:42.068539  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131): perf score=10.126437
I20260812 06:19:42.109196  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.040s	user 0.020s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16094,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:42.109800  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131): perf score=2.188937
I20260812 06:19:42.126050  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.016s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6134,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:42.126622  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling MajorDeltaCompactionOp(a11b5468485649b9a48a9e3e2c231131): perf score=1.000000
I20260812 06:19:42.257822  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: MajorDeltaCompactionOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.131s	user 0.107s	sys 0.024s 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":307,"lbm_read_time_us":9687,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25797,"lbm_writes_lt_1ms":443,"mutex_wait_us":42,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":18560,"update_count":2000}
I20260812 06:19:42.258476  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131): perf score=10.126437
I20260812 06:19:42.310509  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.052s	user 0.036s	sys 0.008s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16073,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:42.311105  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131): perf score=2.188937
I20260812 06:19:42.322070  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4198,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:42.322582  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling MajorDeltaCompactionOp(a11b5468485649b9a48a9e3e2c231131): perf score=1.000000
I20260812 06:19:42.471978  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: MajorDeltaCompactionOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.149s	user 0.070s	sys 0.075s 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":201,"lbm_read_time_us":10382,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25017,"lbm_writes_lt_1ms":443,"mutex_wait_us":21,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7296,"update_count":2000}
I20260812 06:19:42.472677  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131): perf score=10.126437
I20260812 06:19:42.514528  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.042s	user 0.021s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16020,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:42.515017  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131): perf score=2.188937
I20260812 06:19:42.526392  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.011s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4185,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:42.526891  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling MajorDeltaCompactionOp(a11b5468485649b9a48a9e3e2c231131): perf score=1.000000
I20260812 06:19:42.668992  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: MajorDeltaCompactionOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.142s	user 0.105s	sys 0.036s 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":1419,"lbm_read_time_us":9512,"lbm_reads_lt_1ms":472,"lbm_write_time_us":31126,"lbm_writes_lt_1ms":443,"mutex_wait_us":469,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:42.669764  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131): perf score=10.126437
I20260812 06:19:42.711862  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.042s	user 0.021s	sys 0.012s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":15573,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:42.712442  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131): perf score=2.188937
I20260812 06:19:42.727890  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5636,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:42.728500  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling FlushMRSOp(a11b5468485649b9a48a9e3e2c231131): perf score=1.000000
I20260812 06:19:42.763867  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: FlushMRSOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.035s	user 0.034s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":37,"dirs.run_cpu_time_us":315,"dirs.run_wall_time_us":1606,"drs_written":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1820,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:42.764776  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling LogGCOp(a11b5468485649b9a48a9e3e2c231131): free 115943185 bytes of WAL
I20260812 06:19:42.765021  7045 log_reader.cc:385] T a11b5468485649b9a48a9e3e2c231131: removed 11 log segments from log reader
I20260812 06:19:42.765069  7045 log.cc:1079] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/a11b5468485649b9a48a9e3e2c231131/wal-000000003 (ops 12-16)
I20260812 06:19:42.765100  7045 log.cc:1079] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/a11b5468485649b9a48a9e3e2c231131/wal-000000004 (ops 17-21)
I20260812 06:19:42.765172  7045 log.cc:1079] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/a11b5468485649b9a48a9e3e2c231131/wal-000000005 (ops 22-26)
I20260812 06:19:42.765223  7045 log.cc:1079] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/a11b5468485649b9a48a9e3e2c231131/wal-000000006 (ops 27-31)
I20260812 06:19:42.765269  7045 log.cc:1079] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/a11b5468485649b9a48a9e3e2c231131/wal-000000007 (ops 32-36)
I20260812 06:19:42.765327  7045 log.cc:1079] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/a11b5468485649b9a48a9e3e2c231131/wal-000000008 (ops 37-41)
I20260812 06:19:42.765369  7045 log.cc:1079] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/a11b5468485649b9a48a9e3e2c231131/wal-000000009 (ops 42-46)
I20260812 06:19:42.765417  7045 log.cc:1079] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/a11b5468485649b9a48a9e3e2c231131/wal-000000010 (ops 47-51)
I20260812 06:19:42.765453  7045 log.cc:1079] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/a11b5468485649b9a48a9e3e2c231131/wal-000000011 (ops 52-56)
I20260812 06:19:42.765494  7045 log.cc:1079] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/a11b5468485649b9a48a9e3e2c231131/wal-000000012 (ops 57-61)
I20260812 06:19:42.765539  7045 log.cc:1079] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/a11b5468485649b9a48a9e3e2c231131/wal-000000013 (ops 62-66)
I20260812 06:19:42.795737  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: LogGCOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.031s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:19:42.796197  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling UndoDeltaBlockGCOp(a11b5468485649b9a48a9e3e2c231131): 463 bytes on disk
I20260812 06:19:42.796864  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: UndoDeltaBlockGCOp(a11b5468485649b9a48a9e3e2c231131) 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:19:42.797425  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131): perf score=3.181125
I20260812 06:19:42.816846  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.019s	user 0.010s	sys 0.007s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":7576,"lbm_writes_lt_1ms":113,"reinsert_count":0,"spinlock_wait_cycles":21376,"update_count":550}
I20260812 06:19:42.817373  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131): perf score=2.188937
I20260812 06:19:42.828056  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3958,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:42.828548  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling MajorDeltaCompactionOp(a11b5468485649b9a48a9e3e2c231131): perf score=1.000000
I20260812 06:19:43.006655  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: MajorDeltaCompactionOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.178s	user 0.141s	sys 0.032s 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":58,"lbm_read_time_us":12569,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34765,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"thread_start_us":75,"threads_started":1,"update_count":3000}
I20260812 06:19:43.009120  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131): perf score=14.095187
I20260812 06:19:43.058473  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.049s	user 0.026s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18608,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:43.059088  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131): perf score=2.188937
I20260812 06:19:43.081509  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.022s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7055,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:43.082237  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling MajorDeltaCompactionOp(a11b5468485649b9a48a9e3e2c231131): perf score=1.000000
I20260812 06:19:43.233843  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: MajorDeltaCompactionOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.151s	user 0.126s	sys 0.023s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1225,"lbm_read_time_us":8978,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30816,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":542,"mutex_wait_us":380,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:19:43.234612  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131): perf score=14.095187
I20260812 06:19:43.285702  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.051s	user 0.025s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21856,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:43.286444  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling MajorDeltaCompactionOp(a11b5468485649b9a48a9e3e2c231131): perf score=1.000000
I20260812 06:19:43.430800  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: MajorDeltaCompactionOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.144s	user 0.081s	sys 0.057s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":602,"lbm_read_time_us":9469,"lbm_reads_lt_1ms":463,"lbm_write_time_us":23397,"lbm_writes_lt_1ms":443,"mutex_wait_us":286,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:43.431432  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131): perf score=14.095187
I20260812 06:19:43.483173  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.052s	user 0.023s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20261,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:43.483650  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131): perf score=2.188937
I20260812 06:19:43.495563  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4190,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:43.496141  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling MajorDeltaCompactionOp(a11b5468485649b9a48a9e3e2c231131): perf score=1.000000
I20260812 06:19:43.672910  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: MajorDeltaCompactionOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.177s	user 0.103s	sys 0.065s 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":687,"lbm_read_time_us":10530,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26953,"lbm_writes_lt_1ms":543,"mutex_wait_us":316,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5376,"update_count":2500}
I20260812 06:19:43.673620  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131): perf score=14.095187
I20260812 06:19:43.725063  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.051s	user 0.022s	sys 0.019s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19898,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:43.725637  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131): perf score=2.188937
I20260812 06:19:43.741622  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.016s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5951,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:43.742401  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling MajorDeltaCompactionOp(a11b5468485649b9a48a9e3e2c231131): perf score=1.000000
I20260812 06:19:43.896495  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: MajorDeltaCompactionOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.154s	user 0.116s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1844,"lbm_read_time_us":10448,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31040,"lbm_writes_lt_1ms":543,"mutex_wait_us":1261,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11648,"update_count":2500}
I20260812 06:19:43.897126  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131): perf score=10.126437
I20260812 06:19:43.934890  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.038s	user 0.013s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15196,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:43.935534  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131): perf score=2.188937
I20260812 06:19:43.951161  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.015s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4698,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:43.951817  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling MajorDeltaCompactionOp(a11b5468485649b9a48a9e3e2c231131): perf score=1.000000
I20260812 06:19:44.085173  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: MajorDeltaCompactionOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.133s	user 0.098s	sys 0.031s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":572,"lbm_read_time_us":8373,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25941,"lbm_writes_lt_1ms":443,"mutex_wait_us":2959,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13440,"update_count":2000}
I20260812 06:19:44.086383  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131): perf score=10.126437
I20260812 06:19:44.126868  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.040s	user 0.018s	sys 0.020s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":18631,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:19:44.127420  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131): perf score=2.188937
I20260812 06:19:44.138235  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4093,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:44.138751  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling FlushMRSOp(a11b5468485649b9a48a9e3e2c231131): perf score=1.000000
I20260812 06:19:44.171422  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: FlushMRSOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.032s	user 0.026s	sys 0.004s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":238,"dirs.run_wall_time_us":1312,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1645,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:44.172225  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling LogGCOp(a11b5468485649b9a48a9e3e2c231131): free 121006381 bytes of WAL
I20260812 06:19:44.172502  7045 log_reader.cc:385] T a11b5468485649b9a48a9e3e2c231131: removed 12 log segments from log reader
I20260812 06:19:44.172580  7045 log.cc:1079] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/a11b5468485649b9a48a9e3e2c231131/wal-000000014 (ops 67-71)
I20260812 06:19:44.172632  7045 log.cc:1079] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/a11b5468485649b9a48a9e3e2c231131/wal-000000015 (ops 72-76)
I20260812 06:19:44.172690  7045 log.cc:1079] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/a11b5468485649b9a48a9e3e2c231131/wal-000000016 (ops 77-81)
I20260812 06:19:44.172734  7045 log.cc:1079] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/a11b5468485649b9a48a9e3e2c231131/wal-000000017 (ops 82-86)
I20260812 06:19:44.172775  7045 log.cc:1079] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/a11b5468485649b9a48a9e3e2c231131/wal-000000018 (ops 87-91)
I20260812 06:19:44.172814  7045 log.cc:1079] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/a11b5468485649b9a48a9e3e2c231131/wal-000000019 (ops 92-96)
I20260812 06:19:44.172852  7045 log.cc:1079] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/a11b5468485649b9a48a9e3e2c231131/wal-000000020 (ops 97-101)
I20260812 06:19:44.172891  7045 log.cc:1079] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/a11b5468485649b9a48a9e3e2c231131/wal-000000021 (ops 102-106)
I20260812 06:19:44.172940  7045 log.cc:1079] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/a11b5468485649b9a48a9e3e2c231131/wal-000000022 (ops 107-110)
I20260812 06:19:44.172978  7045 log.cc:1079] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/a11b5468485649b9a48a9e3e2c231131/wal-000000023 (ops 111-115)
I20260812 06:19:44.173017  7045 log.cc:1079] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/a11b5468485649b9a48a9e3e2c231131/wal-000000024 (ops 116-120)
I20260812 06:19:44.173062  7045 log.cc:1079] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/a11b5468485649b9a48a9e3e2c231131/wal-000000025 (ops 121-125)
I20260812 06:19:44.200721  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: LogGCOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.028s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:19:44.201220  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131): perf score=3.181125
I20260812 06:19:44.221885  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.020s	user 0.018s	sys 0.000s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":7047,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:44.222400  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131): perf score=2.188937
I20260812 06:19:44.232812  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3929,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:44.233353  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling MajorDeltaCompactionOp(a11b5468485649b9a48a9e3e2c231131): perf score=1.000000
I20260812 06:19:44.409579  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: MajorDeltaCompactionOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.176s	user 0.116s	sys 0.060s 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":2126,"lbm_read_time_us":12663,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34622,"lbm_writes_lt_1ms":643,"mutex_wait_us":571,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1664,"thread_start_us":78,"threads_started":1,"update_count":3000}
I20260812 06:19:44.410260  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling UndoDeltaBlockGCOp(a11b5468485649b9a48a9e3e2c231131): 462 bytes on disk
I20260812 06:19:44.410751  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: UndoDeltaBlockGCOp(a11b5468485649b9a48a9e3e2c231131) 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:19:44.411432  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131): perf score=14.095187
I20260812 06:19:44.468312  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.057s	user 0.015s	sys 0.036s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24086,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:44.468825  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131): perf score=2.188937
I20260812 06:19:44.480250  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4152,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:44.480917  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling MajorDeltaCompactionOp(a11b5468485649b9a48a9e3e2c231131): perf score=1.000000
I20260812 06:19:44.643421  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: MajorDeltaCompactionOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.162s	user 0.119s	sys 0.031s 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":329,"lbm_read_time_us":11612,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28014,"lbm_writes_lt_1ms":543,"mutex_wait_us":58,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2500}
I20260812 06:19:44.644225  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131): perf score=14.095187
I20260812 06:19:44.694209  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.050s	user 0.026s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21792,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:44.695048  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling MajorDeltaCompactionOp(a11b5468485649b9a48a9e3e2c231131): perf score=1.000000
I20260812 06:19:44.843174  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: MajorDeltaCompactionOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.148s	user 0.087s	sys 0.060s 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":812,"lbm_read_time_us":8971,"lbm_reads_lt_1ms":467,"lbm_write_time_us":27063,"lbm_writes_lt_1ms":443,"mutex_wait_us":47,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5376,"update_count":2000}
I20260812 06:19:44.843894  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131): perf score=10.126437
I20260812 06:19:44.887804  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.044s	user 0.028s	sys 0.013s Metrics: {"bytes_written":12307494,"delete_count":0,"lbm_write_time_us":19054,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:44.888563  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131): perf score=2.188937
I20260812 06:19:44.905079  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.016s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6153,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:44.905648  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling MajorDeltaCompactionOp(a11b5468485649b9a48a9e3e2c231131): perf score=1.000000
I20260812 06:19:45.029464  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: MajorDeltaCompactionOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.124s	user 0.090s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672281,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":270,"lbm_read_time_us":7743,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24845,"lbm_writes_lt_1ms":443,"mutex_wait_us":45,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:19:45.031265  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131): perf score=11.118625
I20260812 06:19:45.071677  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.040s	user 0.027s	sys 0.011s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17517,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:45.072206  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131): perf score=2.188937
I20260812 06:19:45.090523  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.018s	user 0.015s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5888,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:45.091253  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling MajorDeltaCompactionOp(a11b5468485649b9a48a9e3e2c231131): perf score=1.000000
I20260812 06:19:45.218017  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: MajorDeltaCompactionOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.127s	user 0.102s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1199,"lbm_read_time_us":8377,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26676,"lbm_writes_lt_1ms":443,"mutex_wait_us":397,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":22016,"update_count":2000}
I20260812 06:19:45.218801  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131): perf score=10.126437
I20260812 06:19:45.265221  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.046s	user 0.031s	sys 0.012s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":21189,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":300,"reinsert_count":0,"update_count":1500}
I20260812 06:19:45.265880  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131): perf score=2.188937
I20260812 06:19:45.277976  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.012s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4508,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:45.278448  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling MajorDeltaCompactionOp(a11b5468485649b9a48a9e3e2c231131): perf score=1.000000
I20260812 06:19:45.408144  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: MajorDeltaCompactionOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.130s	user 0.101s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672280,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":341,"lbm_read_time_us":9841,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26168,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":18432,"update_count":2000}
I20260812 06:19:45.408813  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131): perf score=10.126437
I20260812 06:19:45.465567  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.056s	user 0.020s	sys 0.022s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16323,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:45.466326  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131): perf score=2.188937
I20260812 06:19:45.483482  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.017s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6454,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:45.484110  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling MajorDeltaCompactionOp(a11b5468485649b9a48a9e3e2c231131): perf score=1.000000
I20260812 06:19:45.636600  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: MajorDeltaCompactionOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.152s	user 0.107s	sys 0.044s 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":346,"lbm_read_time_us":11450,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25850,"lbm_writes_lt_1ms":443,"mutex_wait_us":72,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10112,"update_count":2000}
I20260812 06:19:45.637297  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131): perf score=10.126437
I20260812 06:19:45.682174  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.045s	user 0.033s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18079,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:45.682667  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131): perf score=2.188937
I20260812 06:19:45.694537  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4209,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:45.695096  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling FlushMRSOp(a11b5468485649b9a48a9e3e2c231131): perf score=1.000000
I20260812 06:19:45.729085  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: FlushMRSOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.034s	user 0.028s	sys 0.004s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":113,"dirs.run_cpu_time_us":336,"dirs.run_wall_time_us":1427,"drs_written":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2139,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:45.729983  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling LogGCOp(a11b5468485649b9a48a9e3e2c231131): free 133024683 bytes of WAL
I20260812 06:19:45.730302  7045 log_reader.cc:385] T a11b5468485649b9a48a9e3e2c231131: removed 13 log segments from log reader
I20260812 06:19:45.730365  7045 log.cc:1079] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/a11b5468485649b9a48a9e3e2c231131/wal-000000026 (ops 126-130)
I20260812 06:19:45.730401  7045 log.cc:1079] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/a11b5468485649b9a48a9e3e2c231131/wal-000000027 (ops 131-134)
I20260812 06:19:45.730430  7045 log.cc:1079] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/a11b5468485649b9a48a9e3e2c231131/wal-000000028 (ops 135-139)
I20260812 06:19:45.730460  7045 log.cc:1079] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/a11b5468485649b9a48a9e3e2c231131/wal-000000029 (ops 140-144)
I20260812 06:19:45.730492  7045 log.cc:1079] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/a11b5468485649b9a48a9e3e2c231131/wal-000000030 (ops 145-149)
I20260812 06:19:45.730523  7045 log.cc:1079] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/a11b5468485649b9a48a9e3e2c231131/wal-000000031 (ops 150-154)
I20260812 06:19:45.730554  7045 log.cc:1079] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/a11b5468485649b9a48a9e3e2c231131/wal-000000032 (ops 155-159)
I20260812 06:19:45.730576  7045 log.cc:1079] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/a11b5468485649b9a48a9e3e2c231131/wal-000000033 (ops 160-164)
I20260812 06:19:45.730602  7045 log.cc:1079] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/a11b5468485649b9a48a9e3e2c231131/wal-000000034 (ops 165-169)
I20260812 06:19:45.730636  7045 log.cc:1079] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/a11b5468485649b9a48a9e3e2c231131/wal-000000035 (ops 170-174)
I20260812 06:19:45.730664  7045 log.cc:1079] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/a11b5468485649b9a48a9e3e2c231131/wal-000000036 (ops 175-179)
I20260812 06:19:45.730691  7045 log.cc:1079] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/a11b5468485649b9a48a9e3e2c231131/wal-000000037 (ops 180-184)
I20260812 06:19:45.730719  7045 log.cc:1079] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/a11b5468485649b9a48a9e3e2c231131/wal-000000038 (ops 185-189)
I20260812 06:19:45.763070  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: LogGCOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.033s	user 0.000s	sys 0.032s Metrics: {}
I20260812 06:19:45.763561  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling UndoDeltaBlockGCOp(a11b5468485649b9a48a9e3e2c231131): 482 bytes on disk
I20260812 06:19:45.764096  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: UndoDeltaBlockGCOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":67,"lbm_reads_lt_1ms":4}
I20260812 06:19:45.764720  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131): perf score=3.181125
I20260812 06:19:45.792634  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.028s	user 0.007s	sys 0.018s Metrics: {"bytes_written":5005190,"delete_count":0,"lbm_write_time_us":6703,"lbm_writes_lt_1ms":125,"reinsert_count":0,"update_count":610}
I20260812 06:19:45.793272  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131): perf score=2.188937
I20260812 06:19:45.808368  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3200105,"delete_count":0,"lbm_write_time_us":5379,"lbm_writes_lt_1ms":81,"reinsert_count":0,"update_count":390}
I20260812 06:19:45.809062  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling MajorDeltaCompactionOp(a11b5468485649b9a48a9e3e2c231131): perf score=1.000000
I20260812 06:19:46.025260  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: MajorDeltaCompactionOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.216s	user 0.119s	sys 0.096s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877316,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":407,"lbm_read_time_us":15952,"lbm_reads_lt_1ms":674,"lbm_write_time_us":37504,"lbm_writes_lt_1ms":643,"mutex_wait_us":31,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":16128,"thread_start_us":109,"threads_started":1,"update_count":3000}
I20260812 06:19:46.026927  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131): perf score=14.095187
I20260812 06:19:46.057518  6936 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.944s	user 1.842s	sys 0.121s
I20260812 06:19:46.076635  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.047s	user 0.034s	sys 0.011s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21718,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:19:46.077194  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131): perf score=2.188937
I20260812 06:19:46.088968  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: FlushDeltaMemStoresOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.012s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4947,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:46.089498  7110 maintenance_manager.cc:419] P 7840f8c7faa24f7d977a446b3f27e11b: Scheduling MajorDeltaCompactionOp(a11b5468485649b9a48a9e3e2c231131): perf score=1.000000
I20260812 06:19:46.109025  6936 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.051s	user 0.001s	sys 0.000s
I20260812 06:19:46.109763  6936 tablet_server.cc:179] TabletServer@127.6.198.1:0 shutting down...
I20260812 06:19:46.236186  7045 maintenance_manager.cc:643] P 7840f8c7faa24f7d977a446b3f27e11b: MajorDeltaCompactionOp(a11b5468485649b9a48a9e3e2c231131) complete. Timing: real 0.146s	user 0.091s	sys 0.053s Metrics: {"cfile_cache_hit":30,"cfile_cache_hit_bytes":4262390,"cfile_cache_miss":502,"cfile_cache_miss_bytes":20512300,"cfile_init":4,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":696,"lbm_read_time_us":8729,"lbm_reads_lt_1ms":518,"lbm_write_time_us":24096,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:46.236932  6936 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:46.237430  6936 tablet_replica.cc:333] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b: stopping tablet replica
I20260812 06:19:46.237668  6936 raft_consensus.cc:2243] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:46.237952  6936 raft_consensus.cc:2272] T a11b5468485649b9a48a9e3e2c231131 P 7840f8c7faa24f7d977a446b3f27e11b [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:46.254541  6936 tablet_server.cc:196] TabletServer@127.6.198.1:0 shutdown complete.
I20260812 06:19:46.284449  6936 master.cc:562] Master@127.6.198.62:43143 shutting down...
I20260812 06:19:46.288602  6936 raft_consensus.cc:2243] T 00000000000000000000000000000000 P ba11cc38bdc54c5a83ff6e852ad76ace [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:46.288837  6936 raft_consensus.cc:2272] T 00000000000000000000000000000000 P ba11cc38bdc54c5a83ff6e852ad76ace [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:46.288929  6936 tablet_replica.cc:333] T 00000000000000000000000000000000 P ba11cc38bdc54c5a83ff6e852ad76ace: stopping tablet replica
I20260812 06:19:46.301389  6936 master.cc:584] Master@127.6.198.62:43143 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5580 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:46.393926  6936 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.6.198.62:42239
I20260812 06:19:46.394335  6936 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:46.396694  7147 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:46.396705  7144 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:46.396812  6936 server_base.cc:1061] running on GCE node
W20260812 06:19:46.396705  7145 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:46.397089  6936 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:46.397142  6936 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:46.397158  6936 hybrid_clock.cc:648] HybridClock initialized: now 1786515586397158 us; error 0 us; skew 500 ppm
I20260812 06:19:46.398015  6936 webserver.cc:533] Webserver started at http://127.6.198.62:45081/ using document root <none> and password file <none>
I20260812 06:19:46.398195  6936 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:46.398243  6936 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:46.398296  6936 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:46.398622  6936 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580803184-6936-0/minicluster-data/master-0-root/instance:
uuid: "e2f749d3cc8b4729b78631686118fc89"
format_stamp: "Formatted at 2026-08-12 06:19:46 on dist-test-slave-0kls"
I20260812 06:19:46.400058  6936 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:46.400934  7152 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:46.401173  6936 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:46.401268  6936 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580803184-6936-0/minicluster-data/master-0-root
uuid: "e2f749d3cc8b4729b78631686118fc89"
format_stamp: "Formatted at 2026-08-12 06:19:46 on dist-test-slave-0kls"
I20260812 06:19:46.401355  6936 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580803184-6936-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580803184-6936-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580803184-6936-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:46.411422  6936 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:46.411819  6936 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:46.416282  6936 rpc_server.cc:307] RPC server started. Bound to: 127.6.198.62:42239
I20260812 06:19:46.419365  7207 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:46.420642  7206 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.6.198.62:42239 every 8 connection(s)
I20260812 06:19:46.431751  7207 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P e2f749d3cc8b4729b78631686118fc89: Bootstrap starting.
I20260812 06:19:46.432608  7207 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P e2f749d3cc8b4729b78631686118fc89: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:46.433666  7207 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P e2f749d3cc8b4729b78631686118fc89: No bootstrap required, opened a new log
I20260812 06:19:46.434103  7207 raft_consensus.cc:359] T 00000000000000000000000000000000 P e2f749d3cc8b4729b78631686118fc89 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e2f749d3cc8b4729b78631686118fc89" member_type: VOTER }
I20260812 06:19:46.434190  7207 raft_consensus.cc:385] T 00000000000000000000000000000000 P e2f749d3cc8b4729b78631686118fc89 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:46.434265  7207 raft_consensus.cc:740] T 00000000000000000000000000000000 P e2f749d3cc8b4729b78631686118fc89 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: e2f749d3cc8b4729b78631686118fc89, State: Initialized, Role: FOLLOWER
I20260812 06:19:46.434468  7207 consensus_queue.cc:260] T 00000000000000000000000000000000 P e2f749d3cc8b4729b78631686118fc89 [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: "e2f749d3cc8b4729b78631686118fc89" member_type: VOTER }
I20260812 06:19:46.434559  7207 raft_consensus.cc:399] T 00000000000000000000000000000000 P e2f749d3cc8b4729b78631686118fc89 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:46.434607  7207 raft_consensus.cc:493] T 00000000000000000000000000000000 P e2f749d3cc8b4729b78631686118fc89 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:46.434662  7207 raft_consensus.cc:3060] T 00000000000000000000000000000000 P e2f749d3cc8b4729b78631686118fc89 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:46.435380  7207 raft_consensus.cc:515] T 00000000000000000000000000000000 P e2f749d3cc8b4729b78631686118fc89 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e2f749d3cc8b4729b78631686118fc89" member_type: VOTER }
I20260812 06:19:46.435497  7207 leader_election.cc:304] T 00000000000000000000000000000000 P e2f749d3cc8b4729b78631686118fc89 [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: e2f749d3cc8b4729b78631686118fc89; no voters: 
I20260812 06:19:46.435742  7207 leader_election.cc:290] T 00000000000000000000000000000000 P e2f749d3cc8b4729b78631686118fc89 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:46.435916  7211 raft_consensus.cc:2804] T 00000000000000000000000000000000 P e2f749d3cc8b4729b78631686118fc89 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:46.436112  7211 raft_consensus.cc:697] T 00000000000000000000000000000000 P e2f749d3cc8b4729b78631686118fc89 [term 1 LEADER]: Becoming Leader. State: Replica: e2f749d3cc8b4729b78631686118fc89, State: Running, Role: LEADER
I20260812 06:19:46.436246  7207 sys_catalog.cc:565] T 00000000000000000000000000000000 P e2f749d3cc8b4729b78631686118fc89 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:46.436283  7211 consensus_queue.cc:237] T 00000000000000000000000000000000 P e2f749d3cc8b4729b78631686118fc89 [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: "e2f749d3cc8b4729b78631686118fc89" member_type: VOTER }
I20260812 06:19:46.436710  7213 sys_catalog.cc:455] T 00000000000000000000000000000000 P e2f749d3cc8b4729b78631686118fc89 [sys.catalog]: SysCatalogTable state changed. Reason: New leader e2f749d3cc8b4729b78631686118fc89. Latest consensus state: current_term: 1 leader_uuid: "e2f749d3cc8b4729b78631686118fc89" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e2f749d3cc8b4729b78631686118fc89" member_type: VOTER } }
I20260812 06:19:46.436694  7212 sys_catalog.cc:455] T 00000000000000000000000000000000 P e2f749d3cc8b4729b78631686118fc89 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "e2f749d3cc8b4729b78631686118fc89" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e2f749d3cc8b4729b78631686118fc89" member_type: VOTER } }
I20260812 06:19:46.436803  7213 sys_catalog.cc:458] T 00000000000000000000000000000000 P e2f749d3cc8b4729b78631686118fc89 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:46.436813  7212 sys_catalog.cc:458] T 00000000000000000000000000000000 P e2f749d3cc8b4729b78631686118fc89 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:46.437072  7216 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:46.437907  7216 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:46.438223  6936 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:46.439806  7216 catalog_manager.cc:1383] Generated new cluster ID: e1139225c97f49f0a4e3db160102b226
I20260812 06:19:46.439854  7216 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:46.465121  7216 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:46.465709  7216 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:46.476234  7216 catalog_manager.cc:6092] T 00000000000000000000000000000000 P e2f749d3cc8b4729b78631686118fc89: Generated new TSK 0
I20260812 06:19:46.476449  7216 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:46.502995  6936 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:46.505089  7229 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:46.505132  7232 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:46.505215  7230 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:46.505484  6936 server_base.cc:1061] running on GCE node
I20260812 06:19:46.505676  6936 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:46.505724  6936 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:46.505740  6936 hybrid_clock.cc:648] HybridClock initialized: now 1786515586505740 us; error 0 us; skew 500 ppm
I20260812 06:19:46.506606  6936 webserver.cc:533] Webserver started at http://127.6.198.1:45035/ using document root <none> and password file <none>
I20260812 06:19:46.506814  6936 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:46.506891  6936 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:46.506978  6936 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:46.507428  6936 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580803184-6936-0/minicluster-data/ts-0-root/instance:
uuid: "6b8035448e6f4b699535004a66839fec"
format_stamp: "Formatted at 2026-08-12 06:19:46 on dist-test-slave-0kls"
I20260812 06:19:46.508996  6936 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:19:46.509950  7237 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:46.510214  6936 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:46.510282  6936 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580803184-6936-0/minicluster-data/ts-0-root
uuid: "6b8035448e6f4b699535004a66839fec"
format_stamp: "Formatted at 2026-08-12 06:19:46 on dist-test-slave-0kls"
I20260812 06:19:46.510377  6936 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580803184-6936-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580803184-6936-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580803184-6936-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:46.531765  6936 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:46.532214  6936 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:46.532593  6936 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:46.533170  6936 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:46.533211  6936 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:46.533270  6936 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:46.533309  6936 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:46.537897  6936 rpc_server.cc:307] RPC server started. Bound to: 127.6.198.1:34769
I20260812 06:19:46.537936  7307 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.6.198.1:34769 every 8 connection(s)
I20260812 06:19:46.546380  7308 heartbeater.cc:344] Connected to a master server at 127.6.198.62:42239
I20260812 06:19:46.546540  7308 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:46.546804  7308 heartbeater.cc:507] Master 127.6.198.62:42239 requested a full tablet report, sending...
I20260812 06:19:46.547451  7170 ts_manager.cc:194] Registered new tserver with Master: 6b8035448e6f4b699535004a66839fec (127.6.198.1:34769)
I20260812 06:19:46.548171  7170 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:39654
I20260812 06:19:46.548431  6936 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.010041765s
I20260812 06:19:46.554935  7170 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:39668:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:46.563385  7269 tablet_service.cc:1511] Processing CreateTablet for tablet 00adab052b6b41dc9a794b2768ca41e0 (DEFAULT_TABLE table=heavy-update-compaction-test [id=0dd9f07ed9c542fa9c052f589ac0993a]), partition=
I20260812 06:19:46.563656  7269 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00adab052b6b41dc9a794b2768ca41e0. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:46.565564  7320 tablet_bootstrap.cc:492] T 00adab052b6b41dc9a794b2768ca41e0 P 6b8035448e6f4b699535004a66839fec: Bootstrap starting.
I20260812 06:19:46.566610  7320 tablet_bootstrap.cc:654] T 00adab052b6b41dc9a794b2768ca41e0 P 6b8035448e6f4b699535004a66839fec: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:46.567788  7320 tablet_bootstrap.cc:492] T 00adab052b6b41dc9a794b2768ca41e0 P 6b8035448e6f4b699535004a66839fec: No bootstrap required, opened a new log
I20260812 06:19:46.567898  7320 ts_tablet_manager.cc:1403] T 00adab052b6b41dc9a794b2768ca41e0 P 6b8035448e6f4b699535004a66839fec: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:46.568353  7320 raft_consensus.cc:359] T 00adab052b6b41dc9a794b2768ca41e0 P 6b8035448e6f4b699535004a66839fec [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6b8035448e6f4b699535004a66839fec" member_type: VOTER last_known_addr { host: "127.6.198.1" port: 34769 } }
I20260812 06:19:46.568476  7320 raft_consensus.cc:385] T 00adab052b6b41dc9a794b2768ca41e0 P 6b8035448e6f4b699535004a66839fec [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:46.568526  7320 raft_consensus.cc:740] T 00adab052b6b41dc9a794b2768ca41e0 P 6b8035448e6f4b699535004a66839fec [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 6b8035448e6f4b699535004a66839fec, State: Initialized, Role: FOLLOWER
I20260812 06:19:46.568686  7320 consensus_queue.cc:260] T 00adab052b6b41dc9a794b2768ca41e0 P 6b8035448e6f4b699535004a66839fec [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: "6b8035448e6f4b699535004a66839fec" member_type: VOTER last_known_addr { host: "127.6.198.1" port: 34769 } }
I20260812 06:19:46.568804  7320 raft_consensus.cc:399] T 00adab052b6b41dc9a794b2768ca41e0 P 6b8035448e6f4b699535004a66839fec [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:46.568861  7320 raft_consensus.cc:493] T 00adab052b6b41dc9a794b2768ca41e0 P 6b8035448e6f4b699535004a66839fec [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:46.568917  7320 raft_consensus.cc:3060] T 00adab052b6b41dc9a794b2768ca41e0 P 6b8035448e6f4b699535004a66839fec [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:46.569850  7320 raft_consensus.cc:515] T 00adab052b6b41dc9a794b2768ca41e0 P 6b8035448e6f4b699535004a66839fec [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6b8035448e6f4b699535004a66839fec" member_type: VOTER last_known_addr { host: "127.6.198.1" port: 34769 } }
I20260812 06:19:46.569983  7320 leader_election.cc:304] T 00adab052b6b41dc9a794b2768ca41e0 P 6b8035448e6f4b699535004a66839fec [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: 6b8035448e6f4b699535004a66839fec; no voters: 
I20260812 06:19:46.570147  7320 leader_election.cc:290] T 00adab052b6b41dc9a794b2768ca41e0 P 6b8035448e6f4b699535004a66839fec [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:46.570284  7322 raft_consensus.cc:2804] T 00adab052b6b41dc9a794b2768ca41e0 P 6b8035448e6f4b699535004a66839fec [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:46.570477  7320 ts_tablet_manager.cc:1434] T 00adab052b6b41dc9a794b2768ca41e0 P 6b8035448e6f4b699535004a66839fec: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.002s
I20260812 06:19:46.570542  7322 raft_consensus.cc:697] T 00adab052b6b41dc9a794b2768ca41e0 P 6b8035448e6f4b699535004a66839fec [term 1 LEADER]: Becoming Leader. State: Replica: 6b8035448e6f4b699535004a66839fec, State: Running, Role: LEADER
I20260812 06:19:46.570497  7308 heartbeater.cc:499] Master 127.6.198.62:42239 was elected leader, sending a full tablet report...
I20260812 06:19:46.570747  7322 consensus_queue.cc:237] T 00adab052b6b41dc9a794b2768ca41e0 P 6b8035448e6f4b699535004a66839fec [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: "6b8035448e6f4b699535004a66839fec" member_type: VOTER last_known_addr { host: "127.6.198.1" port: 34769 } }
I20260812 06:19:46.572073  7170 catalog_manager.cc:5719] T 00adab052b6b41dc9a794b2768ca41e0 P 6b8035448e6f4b699535004a66839fec reported cstate change: term changed from 0 to 1, leader changed from <none> to 6b8035448e6f4b699535004a66839fec (127.6.198.1). New cstate: current_term: 1 leader_uuid: "6b8035448e6f4b699535004a66839fec" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6b8035448e6f4b699535004a66839fec" member_type: VOTER last_known_addr { host: "127.6.198.1" port: 34769 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:46.632159  6936 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.053s	user 0.015s	sys 0.008s
I20260812 06:19:46.788894  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling FlushMRSOp(00adab052b6b41dc9a794b2768ca41e0): perf score=19.054940
I20260812 06:19:46.946318  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: FlushMRSOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.157s	user 0.112s	sys 0.044s Metrics: {"bytes_written":12307492,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":92,"dirs.run_cpu_time_us":232,"dirs.run_wall_time_us":902,"drs_written":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40331,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:19:46.947060  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling LogGCOp(00adab052b6b41dc9a794b2768ca41e0): free 20743880 bytes of WAL
I20260812 06:19:46.947345  7243 log_reader.cc:385] T 00adab052b6b41dc9a794b2768ca41e0: removed 2 log segments from log reader
I20260812 06:19:46.947408  7243 log.cc:1079] T 00adab052b6b41dc9a794b2768ca41e0 P 6b8035448e6f4b699535004a66839fec: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/00adab052b6b41dc9a794b2768ca41e0/wal-000000001 (ops 1-6)
I20260812 06:19:46.947453  7243 log.cc:1079] T 00adab052b6b41dc9a794b2768ca41e0 P 6b8035448e6f4b699535004a66839fec: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/00adab052b6b41dc9a794b2768ca41e0/wal-000000002 (ops 7-11)
I20260812 06:19:46.952812  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: LogGCOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.006s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:19:46.953459  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling UndoDeltaBlockGCOp(00adab052b6b41dc9a794b2768ca41e0): 16411394 bytes on disk
I20260812 06:19:46.954090  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: UndoDeltaBlockGCOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":78,"lbm_reads_lt_1ms":4}
I20260812 06:19:46.954576  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0): perf score=3.181125
I20260812 06:19:46.980738  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.026s	user 0.005s	sys 0.007s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":5698,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:46.981240  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0): perf score=2.188937
I20260812 06:19:46.991317  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3813,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:46.991792  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling MajorDeltaCompactionOp(00adab052b6b41dc9a794b2768ca41e0): perf score=1.000000
I20260812 06:19:47.164346  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: MajorDeltaCompactionOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.172s	user 0.117s	sys 0.044s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774797,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":527,"lbm_read_time_us":11948,"lbm_reads_lt_1ms":569,"lbm_write_time_us":31066,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13824,"thread_start_us":303,"threads_started":5,"update_count":2500}
I20260812 06:19:47.164901  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0): perf score=14.095187
I20260812 06:19:47.223991  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.059s	user 0.029s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22706,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:47.224485  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0): perf score=2.188937
I20260812 06:19:47.235574  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4016,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:47.236250  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling MajorDeltaCompactionOp(00adab052b6b41dc9a794b2768ca41e0): perf score=1.000000
I20260812 06:19:47.388269  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: MajorDeltaCompactionOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.152s	user 0.119s	sys 0.032s 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":695,"lbm_read_time_us":12481,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29769,"lbm_writes_lt_1ms":543,"mutex_wait_us":306,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8704,"update_count":2500}
I20260812 06:19:47.389091  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0): perf score=10.126437
I20260812 06:19:47.444334  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.055s	user 0.027s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17320,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:47.445039  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0): perf score=2.188937
I20260812 06:19:47.464565  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.019s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7243,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:47.465196  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling MajorDeltaCompactionOp(00adab052b6b41dc9a794b2768ca41e0): perf score=1.000000
I20260812 06:19:47.692230  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: MajorDeltaCompactionOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.227s	user 0.185s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":2027,"dirs.run_cpu_time_us":1370,"dirs.run_wall_time_us":8300,"lbm_read_time_us":13961,"lbm_reads_lt_1ms":464,"lbm_write_time_us":34125,"lbm_writes_lt_1ms":443,"mutex_wait_us":38,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":17152,"update_count":2000}
I20260812 06:19:47.693090  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0): perf score=18.063937
I20260812 06:19:47.797209  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.104s	user 0.049s	sys 0.028s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":34253,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:47.798039  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0): perf score=6.157687
I20260812 06:19:47.841378  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.043s	user 0.018s	sys 0.013s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":13632,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:47.842115  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0): perf score=2.188937
I20260812 06:19:47.860641  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.018s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6831,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:47.861266  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling MajorDeltaCompactionOp(00adab052b6b41dc9a794b2768ca41e0): perf score=1.000000
I20260812 06:19:48.146768  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: MajorDeltaCompactionOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.285s	user 0.197s	sys 0.088s Metrics: {"cfile_cache_miss":833,"cfile_cache_miss_bytes":37082046,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1081,"lbm_read_time_us":26572,"lbm_reads_lt_1ms":873,"lbm_write_time_us":46560,"lbm_writes_lt_1ms":843,"mutex_wait_us":283,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":10368,"update_count":4000}
I20260812 06:19:48.147344  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0): perf score=22.032687
I20260812 06:19:48.229892  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.082s	user 0.045s	sys 0.026s Metrics: {"bytes_written":24614721,"delete_count":0,"lbm_write_time_us":39023,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":602,"reinsert_count":0,"update_count":3000}
I20260812 06:19:48.230373  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0): perf score=3.181125
I20260812 06:19:48.247936  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.017s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":7104,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:48.248502  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0): perf score=2.188937
I20260812 06:19:48.259006  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3740,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:48.259636  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling FlushMRSOp(00adab052b6b41dc9a794b2768ca41e0): perf score=1.000000
I20260812 06:19:48.289212  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: FlushMRSOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.029s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":86,"dirs.run_cpu_time_us":275,"dirs.run_wall_time_us":1455,"drs_written":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1429,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:48.289999  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling LogGCOp(00adab052b6b41dc9a794b2768ca41e0): free 120553374 bytes of WAL
I20260812 06:19:48.290284  7243 log_reader.cc:385] T 00adab052b6b41dc9a794b2768ca41e0: removed 12 log segments from log reader
I20260812 06:19:48.290359  7243 log.cc:1079] T 00adab052b6b41dc9a794b2768ca41e0 P 6b8035448e6f4b699535004a66839fec: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/00adab052b6b41dc9a794b2768ca41e0/wal-000000003 (ops 12-16)
I20260812 06:19:48.290414  7243 log.cc:1079] T 00adab052b6b41dc9a794b2768ca41e0 P 6b8035448e6f4b699535004a66839fec: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/00adab052b6b41dc9a794b2768ca41e0/wal-000000004 (ops 17-21)
I20260812 06:19:48.290473  7243 log.cc:1079] T 00adab052b6b41dc9a794b2768ca41e0 P 6b8035448e6f4b699535004a66839fec: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/00adab052b6b41dc9a794b2768ca41e0/wal-000000005 (ops 22-26)
I20260812 06:19:48.290514  7243 log.cc:1079] T 00adab052b6b41dc9a794b2768ca41e0 P 6b8035448e6f4b699535004a66839fec: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/00adab052b6b41dc9a794b2768ca41e0/wal-000000006 (ops 27-30)
I20260812 06:19:48.290550  7243 log.cc:1079] T 00adab052b6b41dc9a794b2768ca41e0 P 6b8035448e6f4b699535004a66839fec: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/00adab052b6b41dc9a794b2768ca41e0/wal-000000007 (ops 31-35)
I20260812 06:19:48.290594  7243 log.cc:1079] T 00adab052b6b41dc9a794b2768ca41e0 P 6b8035448e6f4b699535004a66839fec: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/00adab052b6b41dc9a794b2768ca41e0/wal-000000008 (ops 36-40)
I20260812 06:19:48.290634  7243 log.cc:1079] T 00adab052b6b41dc9a794b2768ca41e0 P 6b8035448e6f4b699535004a66839fec: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/00adab052b6b41dc9a794b2768ca41e0/wal-000000009 (ops 41-44)
I20260812 06:19:48.290671  7243 log.cc:1079] T 00adab052b6b41dc9a794b2768ca41e0 P 6b8035448e6f4b699535004a66839fec: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/00adab052b6b41dc9a794b2768ca41e0/wal-000000010 (ops 45-49)
I20260812 06:19:48.290707  7243 log.cc:1079] T 00adab052b6b41dc9a794b2768ca41e0 P 6b8035448e6f4b699535004a66839fec: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/00adab052b6b41dc9a794b2768ca41e0/wal-000000011 (ops 50-54)
I20260812 06:19:48.290745  7243 log.cc:1079] T 00adab052b6b41dc9a794b2768ca41e0 P 6b8035448e6f4b699535004a66839fec: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/00adab052b6b41dc9a794b2768ca41e0/wal-000000012 (ops 55-59)
I20260812 06:19:48.290781  7243 log.cc:1079] T 00adab052b6b41dc9a794b2768ca41e0 P 6b8035448e6f4b699535004a66839fec: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/00adab052b6b41dc9a794b2768ca41e0/wal-000000013 (ops 60-64)
I20260812 06:19:48.290817  7243 log.cc:1079] T 00adab052b6b41dc9a794b2768ca41e0 P 6b8035448e6f4b699535004a66839fec: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/00adab052b6b41dc9a794b2768ca41e0/wal-000000014 (ops 65-69)
I20260812 06:19:48.316484  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: LogGCOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.026s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:19:48.316951  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling UndoDeltaBlockGCOp(00adab052b6b41dc9a794b2768ca41e0): 473 bytes on disk
I20260812 06:19:48.317365  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: UndoDeltaBlockGCOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4}
I20260812 06:19:48.317991  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0): perf score=3.181125
I20260812 06:19:48.329859  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4255,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:48.330287  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0): perf score=2.188937
I20260812 06:19:48.340152  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3584,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:48.340641  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling MajorDeltaCompactionOp(00adab052b6b41dc9a794b2768ca41e0): perf score=1.000000
I20260812 06:19:48.611070  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: MajorDeltaCompactionOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.270s	user 0.201s	sys 0.064s Metrics: {"cfile_cache_miss":1035,"cfile_cache_miss_bytes":45287075,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":852,"lbm_read_time_us":18302,"lbm_reads_lt_1ms":1075,"lbm_write_time_us":55773,"lbm_writes_lt_1ms":1043,"mutex_wait_us":103,"peak_mem_usage":125248760,"reinsert_count":0,"spinlock_wait_cycles":26624,"thread_start_us":106,"threads_started":1,"update_count":5000}
I20260812 06:19:48.612030  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0): perf score=20.048312
I20260812 06:19:48.688010  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.075s	user 0.043s	sys 0.015s Metrics: {"bytes_written":22071228,"delete_count":0,"lbm_write_time_us":27543,"lbm_writes_lt_1ms":541,"reinsert_count":0,"update_count":2690}
I20260812 06:19:48.688527  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0): perf score=5.165500
I20260812 06:19:48.711728  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.023s	user 0.008s	sys 0.010s Metrics: {"bytes_written":6646163,"delete_count":0,"lbm_write_time_us":7734,"lbm_writes_lt_1ms":165,"reinsert_count":0,"update_count":810}
I20260812 06:19:48.712292  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling MajorDeltaCompactionOp(00adab052b6b41dc9a794b2768ca41e0): perf score=1.000000
I20260812 06:19:48.937306  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: MajorDeltaCompactionOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.225s	user 0.140s	sys 0.084s Metrics: {"cfile_cache_miss":732,"cfile_cache_miss_bytes":32979513,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":639,"lbm_read_time_us":14872,"lbm_reads_lt_1ms":768,"lbm_write_time_us":37406,"lbm_writes_lt_1ms":743,"mutex_wait_us":83,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":3712,"update_count":3500}
I20260812 06:19:48.939181  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0): perf score=18.063937
I20260812 06:19:48.999135  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.060s	user 0.031s	sys 0.028s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":26723,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:48.999625  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0): perf score=2.188937
I20260812 06:19:49.014971  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5019,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:49.015503  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling MajorDeltaCompactionOp(00adab052b6b41dc9a794b2768ca41e0): perf score=1.000000
I20260812 06:19:49.195358  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: MajorDeltaCompactionOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.180s	user 0.134s	sys 0.044s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877105,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":791,"lbm_read_time_us":11419,"lbm_reads_lt_1ms":664,"lbm_write_time_us":34096,"lbm_writes_lt_1ms":643,"mutex_wait_us":347,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":684288,"update_count":3000}
I20260812 06:19:49.196194  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0): perf score=14.095187
I20260812 06:19:49.241196  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.045s	user 0.033s	sys 0.008s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19428,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:49.241835  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0): perf score=2.188937
I20260812 06:19:49.259796  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.018s	user 0.007s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6893,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:49.260448  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling MajorDeltaCompactionOp(00adab052b6b41dc9a794b2768ca41e0): perf score=1.000000
I20260812 06:19:49.423702  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: MajorDeltaCompactionOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.163s	user 0.115s	sys 0.043s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":230,"lbm_read_time_us":11335,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28346,"lbm_writes_lt_1ms":543,"mutex_wait_us":50,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10112,"update_count":2500}
I20260812 06:19:49.424788  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0): perf score=14.095187
I20260812 06:19:49.477288  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.052s	user 0.038s	sys 0.007s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21695,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:49.477896  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling MajorDeltaCompactionOp(00adab052b6b41dc9a794b2768ca41e0): perf score=1.000000
I20260812 06:19:49.645161  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: MajorDeltaCompactionOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.167s	user 0.120s	sys 0.038s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":252,"lbm_read_time_us":10876,"lbm_reads_lt_1ms":463,"lbm_write_time_us":27472,"lbm_writes_lt_1ms":443,"mutex_wait_us":72,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15488,"update_count":2000}
I20260812 06:19:49.645927  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0): perf score=14.095187
I20260812 06:19:49.702113  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.056s	user 0.028s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22094,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:49.702740  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0): perf score=2.188937
I20260812 06:19:49.718918  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.016s	user 0.009s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6252,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:49.719540  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling FlushMRSOp(00adab052b6b41dc9a794b2768ca41e0): perf score=1.000000
I20260812 06:19:49.761053  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: FlushMRSOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.041s	user 0.031s	sys 0.005s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":101,"dirs.run_cpu_time_us":284,"dirs.run_wall_time_us":1550,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1531,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:49.761762  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling LogGCOp(00adab052b6b41dc9a794b2768ca41e0): free 124710309 bytes of WAL
I20260812 06:19:49.762077  7243 log_reader.cc:385] T 00adab052b6b41dc9a794b2768ca41e0: removed 12 log segments from log reader
I20260812 06:19:49.762149  7243 log.cc:1079] T 00adab052b6b41dc9a794b2768ca41e0 P 6b8035448e6f4b699535004a66839fec: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/00adab052b6b41dc9a794b2768ca41e0/wal-000000015 (ops 70-74)
I20260812 06:19:49.762192  7243 log.cc:1079] T 00adab052b6b41dc9a794b2768ca41e0 P 6b8035448e6f4b699535004a66839fec: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/00adab052b6b41dc9a794b2768ca41e0/wal-000000016 (ops 75-79)
I20260812 06:19:49.762223  7243 log.cc:1079] T 00adab052b6b41dc9a794b2768ca41e0 P 6b8035448e6f4b699535004a66839fec: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/00adab052b6b41dc9a794b2768ca41e0/wal-000000017 (ops 80-84)
I20260812 06:19:49.762250  7243 log.cc:1079] T 00adab052b6b41dc9a794b2768ca41e0 P 6b8035448e6f4b699535004a66839fec: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/00adab052b6b41dc9a794b2768ca41e0/wal-000000018 (ops 85-89)
I20260812 06:19:49.762280  7243 log.cc:1079] T 00adab052b6b41dc9a794b2768ca41e0 P 6b8035448e6f4b699535004a66839fec: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/00adab052b6b41dc9a794b2768ca41e0/wal-000000019 (ops 90-94)
I20260812 06:19:49.762311  7243 log.cc:1079] T 00adab052b6b41dc9a794b2768ca41e0 P 6b8035448e6f4b699535004a66839fec: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/00adab052b6b41dc9a794b2768ca41e0/wal-000000020 (ops 95-99)
I20260812 06:19:49.762348  7243 log.cc:1079] T 00adab052b6b41dc9a794b2768ca41e0 P 6b8035448e6f4b699535004a66839fec: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/00adab052b6b41dc9a794b2768ca41e0/wal-000000021 (ops 100-104)
I20260812 06:19:49.762372  7243 log.cc:1079] T 00adab052b6b41dc9a794b2768ca41e0 P 6b8035448e6f4b699535004a66839fec: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/00adab052b6b41dc9a794b2768ca41e0/wal-000000022 (ops 105-109)
I20260812 06:19:49.762399  7243 log.cc:1079] T 00adab052b6b41dc9a794b2768ca41e0 P 6b8035448e6f4b699535004a66839fec: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/00adab052b6b41dc9a794b2768ca41e0/wal-000000023 (ops 110-114)
I20260812 06:19:49.762425  7243 log.cc:1079] T 00adab052b6b41dc9a794b2768ca41e0 P 6b8035448e6f4b699535004a66839fec: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/00adab052b6b41dc9a794b2768ca41e0/wal-000000024 (ops 115-119)
I20260812 06:19:49.762451  7243 log.cc:1079] T 00adab052b6b41dc9a794b2768ca41e0 P 6b8035448e6f4b699535004a66839fec: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/00adab052b6b41dc9a794b2768ca41e0/wal-000000025 (ops 120-124)
I20260812 06:19:49.762485  7243 log.cc:1079] T 00adab052b6b41dc9a794b2768ca41e0 P 6b8035448e6f4b699535004a66839fec: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/00adab052b6b41dc9a794b2768ca41e0/wal-000000026 (ops 125-129)
I20260812 06:19:49.795861  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: LogGCOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.034s	user 0.000s	sys 0.032s Metrics: {}
I20260812 06:19:49.796371  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling UndoDeltaBlockGCOp(00adab052b6b41dc9a794b2768ca41e0): 462 bytes on disk
I20260812 06:19:49.797015  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: UndoDeltaBlockGCOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":88,"lbm_reads_lt_1ms":4}
I20260812 06:19:49.797608  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0): perf score=2.188937
I20260812 06:19:49.823348  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.025s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4952,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:49.823868  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0): perf score=2.188937
I20260812 06:19:49.834378  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.010s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4030,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:49.834826  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling MajorDeltaCompactionOp(00adab052b6b41dc9a794b2768ca41e0): perf score=1.000000
I20260812 06:19:50.102751  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: MajorDeltaCompactionOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.268s	user 0.200s	sys 0.063s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979750,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1153,"lbm_read_time_us":18285,"lbm_reads_lt_1ms":774,"lbm_write_time_us":45271,"lbm_writes_lt_1ms":743,"mutex_wait_us":439,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":8320,"thread_start_us":95,"threads_started":1,"update_count":3500}
I20260812 06:19:50.103955  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0): perf score=16.079562
I20260812 06:19:50.158905  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.055s	user 0.038s	sys 0.016s Metrics: {"bytes_written":17681657,"delete_count":0,"lbm_write_time_us":24607,"lbm_writes_lt_1ms":434,"reinsert_count":0,"update_count":2155}
I20260812 06:19:50.159412  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0): perf score=1.196750
I20260812 06:19:50.181690  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.022s	user 0.000s	sys 0.007s Metrics: {"bytes_written":2830880,"delete_count":0,"lbm_write_time_us":3158,"lbm_writes_lt_1ms":72,"reinsert_count":0,"update_count":345}
I20260812 06:19:50.182502  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0): perf score=2.188937
I20260812 06:19:50.193120  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3978,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:50.193666  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling MajorDeltaCompactionOp(00adab052b6b41dc9a794b2768ca41e0): perf score=1.000000
I20260812 06:19:50.409013  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: MajorDeltaCompactionOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.215s	user 0.143s	sys 0.069s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877196,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":255,"lbm_read_time_us":15641,"lbm_reads_lt_1ms":673,"lbm_write_time_us":34751,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":21888,"update_count":3000}
I20260812 06:19:50.409710  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0): perf score=14.095187
I20260812 06:19:50.455073  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.045s	user 0.039s	sys 0.004s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19892,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:50.455749  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0): perf score=2.188937
I20260812 06:19:50.471779  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.016s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6492,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:50.472271  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling MajorDeltaCompactionOp(00adab052b6b41dc9a794b2768ca41e0): perf score=1.000000
I20260812 06:19:50.644155  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: MajorDeltaCompactionOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.172s	user 0.137s	sys 0.035s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":270,"lbm_read_time_us":11340,"lbm_reads_lt_1ms":568,"lbm_write_time_us":29803,"lbm_writes_lt_1ms":543,"mutex_wait_us":64,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":19328,"update_count":2500}
I20260812 06:19:50.644935  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0): perf score=14.095187
I20260812 06:19:50.697113  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.052s	user 0.028s	sys 0.021s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":23262,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:50.697748  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0): perf score=2.188937
I20260812 06:19:50.710091  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4277,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:50.710631  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling MajorDeltaCompactionOp(00adab052b6b41dc9a794b2768ca41e0): perf score=1.000000
I20260812 06:19:50.892503  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: MajorDeltaCompactionOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.182s	user 0.108s	sys 0.073s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":756,"lbm_read_time_us":13753,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29233,"lbm_writes_lt_1ms":543,"mutex_wait_us":52,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13440,"update_count":2500}
I20260812 06:19:50.893013  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0): perf score=14.095187
I20260812 06:19:50.949864  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.057s	user 0.039s	sys 0.015s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19334,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:50.950446  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0): perf score=2.188937
I20260812 06:19:50.961421  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4280,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:50.962013  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling MajorDeltaCompactionOp(00adab052b6b41dc9a794b2768ca41e0): perf score=1.000000
I20260812 06:19:51.165606  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: MajorDeltaCompactionOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.203s	user 0.132s	sys 0.062s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":623,"lbm_read_time_us":13407,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32063,"lbm_writes_lt_1ms":543,"mutex_wait_us":309,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2500}
I20260812 06:19:51.166337  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0): perf score=14.095187
I20260812 06:19:51.223438  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.057s	user 0.020s	sys 0.031s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":19922,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:51.224041  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0): perf score=2.188937
I20260812 06:19:51.234866  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4237,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:51.235360  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling FlushMRSOp(00adab052b6b41dc9a794b2768ca41e0): perf score=1.000000
I20260812 06:19:51.280025  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: FlushMRSOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.044s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":88,"dirs.run_cpu_time_us":257,"dirs.run_wall_time_us":1668,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1388,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:51.280786  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling LogGCOp(00adab052b6b41dc9a794b2768ca41e0): free 111786506 bytes of WAL
I20260812 06:19:51.281018  7243 log_reader.cc:385] T 00adab052b6b41dc9a794b2768ca41e0: removed 11 log segments from log reader
I20260812 06:19:51.281061  7243 log.cc:1079] T 00adab052b6b41dc9a794b2768ca41e0 P 6b8035448e6f4b699535004a66839fec: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/00adab052b6b41dc9a794b2768ca41e0/wal-000000027 (ops 130-134)
I20260812 06:19:51.281090  7243 log.cc:1079] T 00adab052b6b41dc9a794b2768ca41e0 P 6b8035448e6f4b699535004a66839fec: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/00adab052b6b41dc9a794b2768ca41e0/wal-000000028 (ops 135-138)
I20260812 06:19:51.281107  7243 log.cc:1079] T 00adab052b6b41dc9a794b2768ca41e0 P 6b8035448e6f4b699535004a66839fec: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/00adab052b6b41dc9a794b2768ca41e0/wal-000000029 (ops 139-143)
I20260812 06:19:51.281124  7243 log.cc:1079] T 00adab052b6b41dc9a794b2768ca41e0 P 6b8035448e6f4b699535004a66839fec: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/00adab052b6b41dc9a794b2768ca41e0/wal-000000030 (ops 144-148)
I20260812 06:19:51.281141  7243 log.cc:1079] T 00adab052b6b41dc9a794b2768ca41e0 P 6b8035448e6f4b699535004a66839fec: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/00adab052b6b41dc9a794b2768ca41e0/wal-000000031 (ops 149-153)
I20260812 06:19:51.281157  7243 log.cc:1079] T 00adab052b6b41dc9a794b2768ca41e0 P 6b8035448e6f4b699535004a66839fec: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/00adab052b6b41dc9a794b2768ca41e0/wal-000000032 (ops 154-158)
I20260812 06:19:51.281212  7243 log.cc:1079] T 00adab052b6b41dc9a794b2768ca41e0 P 6b8035448e6f4b699535004a66839fec: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/00adab052b6b41dc9a794b2768ca41e0/wal-000000033 (ops 159-163)
I20260812 06:19:51.281260  7243 log.cc:1079] T 00adab052b6b41dc9a794b2768ca41e0 P 6b8035448e6f4b699535004a66839fec: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/00adab052b6b41dc9a794b2768ca41e0/wal-000000034 (ops 164-168)
I20260812 06:19:51.281313  7243 log.cc:1079] T 00adab052b6b41dc9a794b2768ca41e0 P 6b8035448e6f4b699535004a66839fec: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/00adab052b6b41dc9a794b2768ca41e0/wal-000000035 (ops 169-172)
I20260812 06:19:51.281360  7243 log.cc:1079] T 00adab052b6b41dc9a794b2768ca41e0 P 6b8035448e6f4b699535004a66839fec: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/00adab052b6b41dc9a794b2768ca41e0/wal-000000036 (ops 173-177)
I20260812 06:19:51.281379  7243 log.cc:1079] T 00adab052b6b41dc9a794b2768ca41e0 P 6b8035448e6f4b699535004a66839fec: Deleting log segment in path: /tmp/dist-test-taskxTbQTr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580803184-6936-0/minicluster-data/ts-0-root/wals/00adab052b6b41dc9a794b2768ca41e0/wal-000000037 (ops 178-182)
I20260812 06:19:51.305611  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: LogGCOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.025s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:19:51.306017  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling UndoDeltaBlockGCOp(00adab052b6b41dc9a794b2768ca41e0): 448 bytes on disk
I20260812 06:19:51.306530  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: UndoDeltaBlockGCOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:19:51.307049  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0): perf score=3.181125
I20260812 06:19:51.321559  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.014s	user 0.004s	sys 0.008s Metrics: {"bytes_written":5087239,"delete_count":0,"lbm_write_time_us":5737,"lbm_writes_lt_1ms":127,"reinsert_count":0,"update_count":620}
I20260812 06:19:51.322099  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0): perf score=1.196750
I20260812 06:19:51.335763  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.013s	user 0.005s	sys 0.006s Metrics: {"bytes_written":3118055,"delete_count":0,"lbm_write_time_us":4707,"lbm_writes_lt_1ms":79,"reinsert_count":0,"update_count":380}
I20260812 06:19:51.336632  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling MajorDeltaCompactionOp(00adab052b6b41dc9a794b2768ca41e0): perf score=1.000000
I20260812 06:19:51.568022  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: MajorDeltaCompactionOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.231s	user 0.150s	sys 0.079s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979729,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":699,"lbm_read_time_us":14808,"lbm_reads_lt_1ms":774,"lbm_write_time_us":38712,"lbm_writes_lt_1ms":743,"mutex_wait_us":63,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1152,"thread_start_us":84,"threads_started":1,"update_count":3500}
I20260812 06:19:51.568606  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0): perf score=18.063937
I20260812 06:19:51.636322  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.068s	user 0.034s	sys 0.020s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":25943,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:51.636883  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0): perf score=2.188937
I20260812 06:19:51.647917  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: FlushDeltaMemStoresOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4085,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:51.648597  7309 maintenance_manager.cc:419] P 6b8035448e6f4b699535004a66839fec: Scheduling MajorDeltaCompactionOp(00adab052b6b41dc9a794b2768ca41e0): perf score=1.000000
I20260812 06:19:51.689251  6936 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.057s	user 1.852s	sys 0.173s
I20260812 06:19:51.772065  6936 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.082s	user 0.001s	sys 0.000s
I20260812 06:19:51.772598  6936 tablet_server.cc:179] TabletServer@127.6.198.1:0 shutting down...
I20260812 06:19:51.834260  7243 maintenance_manager.cc:643] P 6b8035448e6f4b699535004a66839fec: MajorDeltaCompactionOp(00adab052b6b41dc9a794b2768ca41e0) complete. Timing: real 0.185s	user 0.133s	sys 0.052s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877103,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":753,"lbm_read_time_us":15372,"lbm_reads_lt_1ms":668,"lbm_write_time_us":29366,"lbm_writes_lt_1ms":643,"mutex_wait_us":128,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":26880,"update_count":3000}
I20260812 06:19:51.834995  6936 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:51.835201  6936 tablet_replica.cc:333] T 00adab052b6b41dc9a794b2768ca41e0 P 6b8035448e6f4b699535004a66839fec: stopping tablet replica
I20260812 06:19:51.835391  6936 raft_consensus.cc:2243] T 00adab052b6b41dc9a794b2768ca41e0 P 6b8035448e6f4b699535004a66839fec [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:51.835599  6936 raft_consensus.cc:2272] T 00adab052b6b41dc9a794b2768ca41e0 P 6b8035448e6f4b699535004a66839fec [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:51.841336  6936 tablet_server.cc:196] TabletServer@127.6.198.1:0 shutdown complete.
I20260812 06:19:51.888514  6936 master.cc:562] Master@127.6.198.62:42239 shutting down...
I20260812 06:19:51.892359  6936 raft_consensus.cc:2243] T 00000000000000000000000000000000 P e2f749d3cc8b4729b78631686118fc89 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:51.892592  6936 raft_consensus.cc:2272] T 00000000000000000000000000000000 P e2f749d3cc8b4729b78631686118fc89 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:51.892675  6936 tablet_replica.cc:333] T 00000000000000000000000000000000 P e2f749d3cc8b4729b78631686118fc89: stopping tablet replica
I20260812 06:19:51.906551  6936 master.cc:584] Master@127.6.198.62:42239 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5606 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11188 ms total)

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