[==========] 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:00.288304  3032 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.2.246.62:42825
I20260812 06:19:00.289258  3032 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:00.289919  3032 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:00.296013  3038 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:00.296460  3032 server_base.cc:1061] running on GCE node
W20260812 06:19:00.296504  3041 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:00.296902  3039 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:00.297317  3032 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:00.297463  3032 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:00.297498  3032 hybrid_clock.cc:648] HybridClock initialized: now 1786515540297497 us; error 0 us; skew 500 ppm
I20260812 06:19:00.299218  3032 webserver.cc:533] Webserver started at http://127.2.246.62:41999/ using document root <none> and password file <none>
I20260812 06:19:00.299696  3032 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:00.299747  3032 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:00.299914  3032 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:00.301271  3032 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515540278960-3032-0/minicluster-data/master-0-root/instance:
uuid: "84b2273b8eb64575b9a08a9186e593af"
format_stamp: "Formatted at 2026-08-12 06:19:00 on dist-test-slave-6nmv"
I20260812 06:19:00.304473  3032 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:19:00.306586  3046 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:00.307533  3032 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:00.307678  3032 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515540278960-3032-0/minicluster-data/master-0-root
uuid: "84b2273b8eb64575b9a08a9186e593af"
format_stamp: "Formatted at 2026-08-12 06:19:00 on dist-test-slave-6nmv"
I20260812 06:19:00.307781  3032 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515540278960-3032-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515540278960-3032-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515540278960-3032-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:00.329941  3032 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:00.330469  3032 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:00.330636  3032 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:00.337280  3032 rpc_server.cc:307] RPC server started. Bound to: 127.2.246.62:42825
I20260812 06:19:00.337284  3107 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.2.246.62:42825 every 8 connection(s)
I20260812 06:19:00.339373  3108 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:00.344305  3108 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 84b2273b8eb64575b9a08a9186e593af: Bootstrap starting.
I20260812 06:19:00.346305  3108 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 84b2273b8eb64575b9a08a9186e593af: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:00.347113  3108 log.cc:826] T 00000000000000000000000000000000 P 84b2273b8eb64575b9a08a9186e593af: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:00.348546  3108 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 84b2273b8eb64575b9a08a9186e593af: No bootstrap required, opened a new log
I20260812 06:19:00.351028  3108 raft_consensus.cc:359] T 00000000000000000000000000000000 P 84b2273b8eb64575b9a08a9186e593af [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "84b2273b8eb64575b9a08a9186e593af" member_type: VOTER }
I20260812 06:19:00.351164  3108 raft_consensus.cc:385] T 00000000000000000000000000000000 P 84b2273b8eb64575b9a08a9186e593af [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:00.351208  3108 raft_consensus.cc:740] T 00000000000000000000000000000000 P 84b2273b8eb64575b9a08a9186e593af [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 84b2273b8eb64575b9a08a9186e593af, State: Initialized, Role: FOLLOWER
I20260812 06:19:00.351656  3108 consensus_queue.cc:260] T 00000000000000000000000000000000 P 84b2273b8eb64575b9a08a9186e593af [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: "84b2273b8eb64575b9a08a9186e593af" member_type: VOTER }
I20260812 06:19:00.351799  3108 raft_consensus.cc:399] T 00000000000000000000000000000000 P 84b2273b8eb64575b9a08a9186e593af [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:00.351845  3108 raft_consensus.cc:493] T 00000000000000000000000000000000 P 84b2273b8eb64575b9a08a9186e593af [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:00.351933  3108 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 84b2273b8eb64575b9a08a9186e593af [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:00.352576  3108 raft_consensus.cc:515] T 00000000000000000000000000000000 P 84b2273b8eb64575b9a08a9186e593af [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "84b2273b8eb64575b9a08a9186e593af" member_type: VOTER }
I20260812 06:19:00.352929  3108 leader_election.cc:304] T 00000000000000000000000000000000 P 84b2273b8eb64575b9a08a9186e593af [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: 84b2273b8eb64575b9a08a9186e593af; no voters: 
I20260812 06:19:00.353178  3108 leader_election.cc:290] T 00000000000000000000000000000000 P 84b2273b8eb64575b9a08a9186e593af [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:00.353291  3111 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 84b2273b8eb64575b9a08a9186e593af [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:00.353555  3111 raft_consensus.cc:697] T 00000000000000000000000000000000 P 84b2273b8eb64575b9a08a9186e593af [term 1 LEADER]: Becoming Leader. State: Replica: 84b2273b8eb64575b9a08a9186e593af, State: Running, Role: LEADER
I20260812 06:19:00.353981  3111 consensus_queue.cc:237] T 00000000000000000000000000000000 P 84b2273b8eb64575b9a08a9186e593af [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: "84b2273b8eb64575b9a08a9186e593af" member_type: VOTER }
I20260812 06:19:00.354169  3108 sys_catalog.cc:565] T 00000000000000000000000000000000 P 84b2273b8eb64575b9a08a9186e593af [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:00.355682  3113 sys_catalog.cc:455] T 00000000000000000000000000000000 P 84b2273b8eb64575b9a08a9186e593af [sys.catalog]: SysCatalogTable state changed. Reason: New leader 84b2273b8eb64575b9a08a9186e593af. Latest consensus state: current_term: 1 leader_uuid: "84b2273b8eb64575b9a08a9186e593af" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "84b2273b8eb64575b9a08a9186e593af" member_type: VOTER } }
I20260812 06:19:00.355675  3112 sys_catalog.cc:455] T 00000000000000000000000000000000 P 84b2273b8eb64575b9a08a9186e593af [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "84b2273b8eb64575b9a08a9186e593af" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "84b2273b8eb64575b9a08a9186e593af" member_type: VOTER } }
I20260812 06:19:00.355822  3112 sys_catalog.cc:458] T 00000000000000000000000000000000 P 84b2273b8eb64575b9a08a9186e593af [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:00.355822  3113 sys_catalog.cc:458] T 00000000000000000000000000000000 P 84b2273b8eb64575b9a08a9186e593af [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:00.356180  3032 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:19:00.358013  3129 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 84b2273b8eb64575b9a08a9186e593af: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:19:00.358089  3129 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:19:00.358139  3126 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:00.358826  3126 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:00.362811  3126 catalog_manager.cc:1383] Generated new cluster ID: ecf10766b7e340eb8d4b873f70b7e99f
I20260812 06:19:00.362885  3126 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:00.375353  3126 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:00.376055  3126 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:00.383260  3126 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 84b2273b8eb64575b9a08a9186e593af: Generated new TSK 0
I20260812 06:19:00.383791  3126 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:00.388569  3032 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:19:00.391335  3032 server_base.cc:1061] running on GCE node
W20260812 06:19:00.391430  3137 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:00.391340  3135 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:00.391326  3134 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:00.391855  3032 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:00.391909  3032 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:00.391943  3032 hybrid_clock.cc:648] HybridClock initialized: now 1786515540391943 us; error 0 us; skew 500 ppm
I20260812 06:19:00.392829  3032 webserver.cc:533] Webserver started at http://127.2.246.1:33353/ using document root <none> and password file <none>
I20260812 06:19:00.392985  3032 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:00.393038  3032 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:00.393108  3032 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:00.393522  3032 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515540278960-3032-0/minicluster-data/ts-0-root/instance:
uuid: "4aba991fedd5415ebd857baaf5ee7ae1"
format_stamp: "Formatted at 2026-08-12 06:19:00 on dist-test-slave-6nmv"
I20260812 06:19:00.395310  3032 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:00.396359  3146 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:00.396687  3032 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:00.396749  3032 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515540278960-3032-0/minicluster-data/ts-0-root
uuid: "4aba991fedd5415ebd857baaf5ee7ae1"
format_stamp: "Formatted at 2026-08-12 06:19:00 on dist-test-slave-6nmv"
I20260812 06:19:00.396828  3032 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515540278960-3032-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515540278960-3032-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515540278960-3032-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:00.408690  3032 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:00.409080  3032 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:00.409488  3032 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:00.410329  3032 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:00.410391  3032 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:00.410476  3032 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:00.410524  3032 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:00.416579  3032 rpc_server.cc:307] RPC server started. Bound to: 127.2.246.1:39489
I20260812 06:19:00.416642  3212 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.2.246.1:39489 every 8 connection(s)
I20260812 06:19:00.426071  3213 heartbeater.cc:344] Connected to a master server at 127.2.246.62:42825
I20260812 06:19:00.426308  3213 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:00.426790  3213 heartbeater.cc:507] Master 127.2.246.62:42825 requested a full tablet report, sending...
I20260812 06:19:00.428045  3066 ts_manager.cc:194] Registered new tserver with Master: 4aba991fedd5415ebd857baaf5ee7ae1 (127.2.246.1:39489)
I20260812 06:19:00.428542  3032 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011311638s
I20260812 06:19:00.429639  3066 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:55234
I20260812 06:19:00.437556  3066 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:55250:
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:00.451224  3176 tablet_service.cc:1511] Processing CreateTablet for tablet 2e39ec36a3694bf5a2769f406d8d2896 (DEFAULT_TABLE table=heavy-update-compaction-test [id=09fd825e4e0046a5930d0ed53a4bb67f]), partition=
I20260812 06:19:00.451659  3176 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 2e39ec36a3694bf5a2769f406d8d2896. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:00.453677  3226 tablet_bootstrap.cc:492] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1: Bootstrap starting.
I20260812 06:19:00.454612  3226 tablet_bootstrap.cc:654] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:00.455704  3226 tablet_bootstrap.cc:492] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1: No bootstrap required, opened a new log
I20260812 06:19:00.455801  3226 ts_tablet_manager.cc:1403] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:00.456159  3226 raft_consensus.cc:359] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4aba991fedd5415ebd857baaf5ee7ae1" member_type: VOTER last_known_addr { host: "127.2.246.1" port: 39489 } }
I20260812 06:19:00.456248  3226 raft_consensus.cc:385] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:00.456295  3226 raft_consensus.cc:740] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 4aba991fedd5415ebd857baaf5ee7ae1, State: Initialized, Role: FOLLOWER
I20260812 06:19:00.456452  3226 consensus_queue.cc:260] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1 [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: "4aba991fedd5415ebd857baaf5ee7ae1" member_type: VOTER last_known_addr { host: "127.2.246.1" port: 39489 } }
I20260812 06:19:00.456558  3226 raft_consensus.cc:399] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:00.456600  3226 raft_consensus.cc:493] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:00.456647  3226 raft_consensus.cc:3060] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:00.457320  3226 raft_consensus.cc:515] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4aba991fedd5415ebd857baaf5ee7ae1" member_type: VOTER last_known_addr { host: "127.2.246.1" port: 39489 } }
I20260812 06:19:00.457468  3226 leader_election.cc:304] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1 [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: 4aba991fedd5415ebd857baaf5ee7ae1; no voters: 
I20260812 06:19:00.457659  3226 leader_election.cc:290] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:00.457769  3230 raft_consensus.cc:2804] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:00.457983  3226 ts_tablet_manager.cc:1434] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:00.458009  3230 raft_consensus.cc:697] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1 [term 1 LEADER]: Becoming Leader. State: Replica: 4aba991fedd5415ebd857baaf5ee7ae1, State: Running, Role: LEADER
I20260812 06:19:00.458206  3213 heartbeater.cc:499] Master 127.2.246.62:42825 was elected leader, sending a full tablet report...
I20260812 06:19:00.458220  3230 consensus_queue.cc:237] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1 [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: "4aba991fedd5415ebd857baaf5ee7ae1" member_type: VOTER last_known_addr { host: "127.2.246.1" port: 39489 } }
I20260812 06:19:00.460702  3066 catalog_manager.cc:5719] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1 reported cstate change: term changed from 0 to 1, leader changed from <none> to 4aba991fedd5415ebd857baaf5ee7ae1 (127.2.246.1). New cstate: current_term: 1 leader_uuid: "4aba991fedd5415ebd857baaf5ee7ae1" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4aba991fedd5415ebd857baaf5ee7ae1" member_type: VOTER last_known_addr { host: "127.2.246.1" port: 39489 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:00.527204  3032 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.061s	user 0.023s	sys 0.008s
I20260812 06:19:00.667660  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling FlushMRSOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=19.054940
I20260812 06:19:00.849049  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: FlushMRSOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.181s	user 0.114s	sys 0.063s Metrics: {"bytes_written":12963871,"cfile_init":1,"compiler_manager_pool.queue_time_us":179,"delete_count":0,"dirs.queue_time_us":72,"dirs.run_cpu_time_us":241,"dirs.run_wall_time_us":1784,"drs_written":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4,"lbm_write_time_us":44560,"lbm_writes_lt_1ms":773,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":415616,"thread_start_us":116,"threads_started":1,"update_count":1580}
I20260812 06:19:00.850292  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling LogGCOp(2e39ec36a3694bf5a2769f406d8d2896): free 20743880 bytes of WAL
I20260812 06:19:00.850580  3151 log_reader.cc:385] T 2e39ec36a3694bf5a2769f406d8d2896: removed 2 log segments from log reader
I20260812 06:19:00.850644  3151 log.cc:1079] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/2e39ec36a3694bf5a2769f406d8d2896/wal-000000001 (ops 1-6)
I20260812 06:19:00.850693  3151 log.cc:1079] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/2e39ec36a3694bf5a2769f406d8d2896/wal-000000002 (ops 7-11)
I20260812 06:19:00.856235  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: LogGCOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.006s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:19:00.856630  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling UndoDeltaBlockGCOp(2e39ec36a3694bf5a2769f406d8d2896): 16411393 bytes on disk
I20260812 06:19:00.857399  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: UndoDeltaBlockGCOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4}
I20260812 06:19:00.858004  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=5.165500
I20260812 06:19:00.880892  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.023s	user 0.005s	sys 0.015s Metrics: {"bytes_written":6482070,"delete_count":0,"lbm_write_time_us":6744,"lbm_writes_lt_1ms":161,"reinsert_count":0,"update_count":790}
I20260812 06:19:00.881313  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling MajorDeltaCompactionOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=1.000000
I20260812 06:19:01.052412  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: MajorDeltaCompactionOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.171s	user 0.108s	sys 0.062s Metrics: {"cfile_cache_miss":506,"cfile_cache_miss_bytes":23708063,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":456,"lbm_read_time_us":12563,"lbm_reads_lt_1ms":538,"lbm_write_time_us":28240,"lbm_writes_lt_1ms":517,"mutex_wait_us":20,"peak_mem_usage":59968222,"reinsert_count":0,"spinlock_wait_cycles":10752,"thread_start_us":309,"threads_started":5,"update_count":2370}
I20260812 06:19:01.053018  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=11.118625
I20260812 06:19:01.091562  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.038s	user 0.020s	sys 0.016s Metrics: {"bytes_written":13374123,"delete_count":0,"lbm_write_time_us":16787,"lbm_writes_lt_1ms":329,"reinsert_count":0,"update_count":1630}
I20260812 06:19:01.092015  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=2.188937
I20260812 06:19:01.106191  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.014s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5475,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:01.106688  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling MajorDeltaCompactionOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=1.000000
I20260812 06:19:01.231001  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: MajorDeltaCompactionOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.124s	user 0.104s	sys 0.020s Metrics: {"cfile_cache_miss":458,"cfile_cache_miss_bytes":21738910,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":154,"lbm_read_time_us":8754,"lbm_reads_lt_1ms":498,"lbm_write_time_us":25419,"lbm_writes_lt_1ms":469,"mutex_wait_us":21,"peak_mem_usage":53837006,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2130}
I20260812 06:19:01.232296  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=10.126437
I20260812 06:19:01.274539  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.042s	user 0.027s	sys 0.012s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":17793,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:01.275015  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=2.188937
I20260812 06:19:01.284416  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3725,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:01.285012  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling MajorDeltaCompactionOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=1.000000
I20260812 06:19:01.407610  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: MajorDeltaCompactionOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.122s	user 0.099s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":261,"lbm_read_time_us":7870,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23035,"lbm_writes_lt_1ms":443,"mutex_wait_us":45,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":38784,"update_count":2000}
I20260812 06:19:01.408291  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=10.126437
I20260812 06:19:01.451079  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.043s	user 0.017s	sys 0.019s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":16586,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:01.451514  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=2.188937
I20260812 06:19:01.461577  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3992,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:01.462224  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling MajorDeltaCompactionOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=1.000000
I20260812 06:19:01.579409  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: MajorDeltaCompactionOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.117s	user 0.094s	sys 0.022s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":486,"lbm_read_time_us":9010,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22227,"lbm_writes_lt_1ms":443,"mutex_wait_us":294,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10496,"update_count":2000}
I20260812 06:19:01.579945  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=10.126437
I20260812 06:19:01.619630  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.040s	user 0.021s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13649,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:01.620139  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=2.188937
I20260812 06:19:01.631042  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4290,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:01.631429  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling MajorDeltaCompactionOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=1.000000
I20260812 06:19:01.772262  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: MajorDeltaCompactionOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.141s	user 0.093s	sys 0.048s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":230,"lbm_read_time_us":10790,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24395,"lbm_writes_lt_1ms":443,"mutex_wait_us":55,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:19:01.772850  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=10.126437
I20260812 06:19:01.818804  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.046s	user 0.016s	sys 0.015s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":14148,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:01.819245  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=2.188937
I20260812 06:19:01.829874  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3993,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:01.830493  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling MajorDeltaCompactionOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=1.000000
I20260812 06:19:01.952441  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: MajorDeltaCompactionOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.122s	user 0.105s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":389,"lbm_read_time_us":9322,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22557,"lbm_writes_lt_1ms":443,"mutex_wait_us":1,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:19:01.953147  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=10.126437
I20260812 06:19:01.992735  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.039s	user 0.018s	sys 0.019s Metrics: {"bytes_written":12307500,"delete_count":0,"lbm_write_time_us":16870,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:01.993271  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=2.188937
I20260812 06:19:02.006811  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.013s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4966,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:02.007293  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling FlushMRSOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=1.000000
I20260812 06:19:02.031448  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: FlushMRSOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.024s	user 0.018s	sys 0.004s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":58,"dirs.run_cpu_time_us":288,"dirs.run_wall_time_us":1425,"drs_written":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1417,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:02.032361  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling LogGCOp(2e39ec36a3694bf5a2769f406d8d2896): free 112239285 bytes of WAL
I20260812 06:19:02.032613  3151 log_reader.cc:385] T 2e39ec36a3694bf5a2769f406d8d2896: removed 11 log segments from log reader
I20260812 06:19:02.032691  3151 log.cc:1079] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/2e39ec36a3694bf5a2769f406d8d2896/wal-000000003 (ops 12-16)
I20260812 06:19:02.032755  3151 log.cc:1079] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/2e39ec36a3694bf5a2769f406d8d2896/wal-000000004 (ops 17-21)
I20260812 06:19:02.032835  3151 log.cc:1079] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/2e39ec36a3694bf5a2769f406d8d2896/wal-000000005 (ops 22-26)
I20260812 06:19:02.032889  3151 log.cc:1079] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/2e39ec36a3694bf5a2769f406d8d2896/wal-000000006 (ops 27-30)
I20260812 06:19:02.032931  3151 log.cc:1079] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/2e39ec36a3694bf5a2769f406d8d2896/wal-000000007 (ops 31-35)
I20260812 06:19:02.032972  3151 log.cc:1079] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/2e39ec36a3694bf5a2769f406d8d2896/wal-000000008 (ops 36-40)
I20260812 06:19:02.033012  3151 log.cc:1079] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/2e39ec36a3694bf5a2769f406d8d2896/wal-000000009 (ops 41-45)
I20260812 06:19:02.033053  3151 log.cc:1079] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/2e39ec36a3694bf5a2769f406d8d2896/wal-000000010 (ops 46-50)
I20260812 06:19:02.033093  3151 log.cc:1079] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/2e39ec36a3694bf5a2769f406d8d2896/wal-000000011 (ops 51-55)
I20260812 06:19:02.033143  3151 log.cc:1079] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/2e39ec36a3694bf5a2769f406d8d2896/wal-000000012 (ops 56-60)
I20260812 06:19:02.033180  3151 log.cc:1079] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/2e39ec36a3694bf5a2769f406d8d2896/wal-000000013 (ops 61-65)
I20260812 06:19:02.057416  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: LogGCOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.025s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:19:02.057997  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=4.173312
I20260812 06:19:02.072027  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":5374417,"delete_count":0,"lbm_write_time_us":5559,"lbm_writes_lt_1ms":134,"reinsert_count":0,"update_count":655}
I20260812 06:19:02.072456  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling LogGCOp(2e39ec36a3694bf5a2769f406d8d2896): free 12017983 bytes of WAL
I20260812 06:19:02.072690  3151 log_reader.cc:385] T 2e39ec36a3694bf5a2769f406d8d2896: removed 1 log segments from log reader
I20260812 06:19:02.072772  3151 log.cc:1079] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/2e39ec36a3694bf5a2769f406d8d2896/wal-000000014 (ops 66-70)
I20260812 06:19:02.075003  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: LogGCOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.002s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:19:02.075320  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=1.196750
I20260812 06:19:02.089908  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.014s	user 0.007s	sys 0.001s Metrics: {"bytes_written":2830880,"delete_count":0,"lbm_write_time_us":3709,"lbm_writes_lt_1ms":72,"reinsert_count":0,"update_count":345}
I20260812 06:19:02.090546  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling UndoDeltaBlockGCOp(2e39ec36a3694bf5a2769f406d8d2896): 462 bytes on disk
I20260812 06:19:02.091056  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: UndoDeltaBlockGCOp(2e39ec36a3694bf5a2769f406d8d2896) 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:02.091637  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling MajorDeltaCompactionOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=1.000000
I20260812 06:19:02.284607  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: MajorDeltaCompactionOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.193s	user 0.142s	sys 0.039s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877322,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":275,"lbm_read_time_us":13348,"lbm_reads_lt_1ms":666,"lbm_write_time_us":38752,"lbm_writes_lt_1ms":643,"mutex_wait_us":43,"peak_mem_usage":75542472,"reinsert_count":0,"thread_start_us":81,"threads_started":1,"update_count":3000}
I20260812 06:19:02.285213  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=18.063937
I20260812 06:19:02.357501  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.072s	user 0.024s	sys 0.044s Metrics: {"bytes_written":20512314,"delete_count":0,"lbm_write_time_us":34262,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:19:02.358084  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=2.188937
I20260812 06:19:02.377496  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.019s	user 0.001s	sys 0.012s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6037,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:02.377985  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=2.188937
I20260812 06:19:02.387545  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3769,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:02.387914  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling MajorDeltaCompactionOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=1.000000
I20260812 06:19:02.579557  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: MajorDeltaCompactionOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.191s	user 0.127s	sys 0.064s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32979630,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":437,"lbm_read_time_us":14119,"lbm_reads_lt_1ms":773,"lbm_write_time_us":41976,"lbm_writes_lt_1ms":743,"mutex_wait_us":60,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":24704,"update_count":3500}
I20260812 06:19:02.580456  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=14.095187
I20260812 06:19:02.631012  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.050s	user 0.047s	sys 0.000s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21136,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:02.631646  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=2.188937
I20260812 06:19:02.650740  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.019s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5419,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:02.651268  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling MajorDeltaCompactionOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=1.000000
I20260812 06:19:02.787614  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: MajorDeltaCompactionOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.136s	user 0.113s	sys 0.015s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":199,"lbm_read_time_us":8334,"lbm_reads_lt_1ms":564,"lbm_write_time_us":26707,"lbm_writes_lt_1ms":543,"mutex_wait_us":32,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11008,"update_count":2500}
I20260812 06:19:02.788272  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=14.095187
I20260812 06:19:02.844314  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.056s	user 0.029s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20939,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:02.844758  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=2.188937
I20260812 06:19:02.854185  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.009s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3770,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:02.854809  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling MajorDeltaCompactionOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=1.000000
I20260812 06:19:03.025020  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: MajorDeltaCompactionOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.170s	user 0.108s	sys 0.059s 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":271,"lbm_read_time_us":11662,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29482,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16896,"update_count":2500}
I20260812 06:19:03.025569  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=14.095187
I20260812 06:19:03.090270  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.064s	user 0.049s	sys 0.007s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":26029,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:03.090715  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=2.188937
I20260812 06:19:03.101265  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4099,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:03.101972  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling MajorDeltaCompactionOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=1.000000
I20260812 06:19:03.271143  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: MajorDeltaCompactionOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.169s	user 0.118s	sys 0.050s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":222,"lbm_read_time_us":13201,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30831,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:03.271876  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=14.095187
I20260812 06:19:03.323583  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.052s	user 0.041s	sys 0.009s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23034,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:03.324123  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=2.188937
I20260812 06:19:03.342655  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.018s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6188,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:03.343273  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling FlushMRSOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=1.000000
I20260812 06:19:03.368703  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: FlushMRSOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.025s	user 0.024s	sys 0.000s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":54,"dirs.run_cpu_time_us":239,"dirs.run_wall_time_us":1208,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1523,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:03.369369  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling LogGCOp(2e39ec36a3694bf5a2769f406d8d2896): free 108535458 bytes of WAL
I20260812 06:19:03.369592  3151 log_reader.cc:385] T 2e39ec36a3694bf5a2769f406d8d2896: removed 11 log segments from log reader
I20260812 06:19:03.369637  3151 log.cc:1079] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/2e39ec36a3694bf5a2769f406d8d2896/wal-000000015 (ops 71-75)
I20260812 06:19:03.369688  3151 log.cc:1079] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/2e39ec36a3694bf5a2769f406d8d2896/wal-000000016 (ops 76-80)
I20260812 06:19:03.369733  3151 log.cc:1079] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/2e39ec36a3694bf5a2769f406d8d2896/wal-000000017 (ops 81-84)
I20260812 06:19:03.369787  3151 log.cc:1079] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/2e39ec36a3694bf5a2769f406d8d2896/wal-000000018 (ops 85-89)
I20260812 06:19:03.369856  3151 log.cc:1079] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/2e39ec36a3694bf5a2769f406d8d2896/wal-000000019 (ops 90-94)
I20260812 06:19:03.369892  3151 log.cc:1079] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/2e39ec36a3694bf5a2769f406d8d2896/wal-000000020 (ops 95-98)
I20260812 06:19:03.369930  3151 log.cc:1079] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/2e39ec36a3694bf5a2769f406d8d2896/wal-000000021 (ops 99-103)
I20260812 06:19:03.369984  3151 log.cc:1079] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/2e39ec36a3694bf5a2769f406d8d2896/wal-000000022 (ops 104-108)
I20260812 06:19:03.370020  3151 log.cc:1079] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/2e39ec36a3694bf5a2769f406d8d2896/wal-000000023 (ops 109-113)
I20260812 06:19:03.370056  3151 log.cc:1079] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/2e39ec36a3694bf5a2769f406d8d2896/wal-000000024 (ops 114-118)
I20260812 06:19:03.370093  3151 log.cc:1079] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/2e39ec36a3694bf5a2769f406d8d2896/wal-000000025 (ops 119-123)
I20260812 06:19:03.392869  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: LogGCOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.023s	user 0.002s	sys 0.019s Metrics: {}
I20260812 06:19:03.393217  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling UndoDeltaBlockGCOp(2e39ec36a3694bf5a2769f406d8d2896): 472 bytes on disk
I20260812 06:19:03.393699  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: UndoDeltaBlockGCOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:19:03.394395  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=6.157687
I20260812 06:19:03.414069  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.019s	user 0.019s	sys 0.000s Metrics: {"bytes_written":7753813,"delete_count":0,"lbm_write_time_us":7922,"lbm_writes_lt_1ms":192,"reinsert_count":0,"update_count":945}
I20260812 06:19:03.415889  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling LogGCOp(2e39ec36a3694bf5a2769f406d8d2896): free 8767123 bytes of WAL
I20260812 06:19:03.416177  3151 log_reader.cc:385] T 2e39ec36a3694bf5a2769f406d8d2896: removed 1 log segments from log reader
I20260812 06:19:03.416250  3151 log.cc:1079] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/2e39ec36a3694bf5a2769f406d8d2896/wal-000000026 (ops 124-128)
I20260812 06:19:03.417776  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: LogGCOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:19:03.418282  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling MajorDeltaCompactionOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=1.000000
I20260812 06:19:03.625519  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: MajorDeltaCompactionOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.207s	user 0.155s	sys 0.051s Metrics: {"cfile_cache_miss":722,"cfile_cache_miss_bytes":32528368,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":451,"lbm_read_time_us":15666,"lbm_reads_lt_1ms":754,"lbm_write_time_us":37383,"lbm_writes_lt_1ms":732,"mutex_wait_us":73,"peak_mem_usage":86477275,"reinsert_count":0,"spinlock_wait_cycles":3200,"thread_start_us":72,"threads_started":1,"update_count":3445}
I20260812 06:19:03.626194  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=19.056125
I20260812 06:19:03.691459  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.065s	user 0.045s	sys 0.017s Metrics: {"bytes_written":20963583,"delete_count":0,"lbm_write_time_us":28528,"lbm_writes_lt_1ms":514,"reinsert_count":0,"update_count":2555}
I20260812 06:19:03.692010  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=2.188937
I20260812 06:19:03.702736  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4252,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:03.703174  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling MajorDeltaCompactionOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=1.000000
I20260812 06:19:03.858026  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: MajorDeltaCompactionOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.155s	user 0.107s	sys 0.045s Metrics: {"cfile_cache_miss":643,"cfile_cache_miss_bytes":29328370,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":276,"lbm_read_time_us":10529,"lbm_reads_lt_1ms":683,"lbm_write_time_us":33598,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":653,"mutex_wait_us":40,"peak_mem_usage":75993857,"reinsert_count":0,"spinlock_wait_cycles":384,"update_count":3055}
I20260812 06:19:03.858600  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=14.095187
I20260812 06:19:03.901506  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.043s	user 0.021s	sys 0.018s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18645,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:03.902351  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=2.188937
I20260812 06:19:03.917155  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.015s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5834,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:03.917534  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling MajorDeltaCompactionOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=1.000000
I20260812 06:19:04.058389  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: MajorDeltaCompactionOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.141s	user 0.116s	sys 0.024s 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":221,"lbm_read_time_us":8414,"lbm_reads_lt_1ms":564,"lbm_write_time_us":26944,"lbm_writes_lt_1ms":543,"mutex_wait_us":31,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12288,"update_count":2500}
I20260812 06:19:04.059105  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=14.095187
I20260812 06:19:04.107542  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.048s	user 0.037s	sys 0.008s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20997,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:04.108170  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling MajorDeltaCompactionOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=1.000000
I20260812 06:19:04.236267  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: MajorDeltaCompactionOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.128s	user 0.097s	sys 0.027s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672158,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":801,"lbm_read_time_us":8881,"lbm_reads_lt_1ms":463,"lbm_write_time_us":21068,"lbm_writes_lt_1ms":443,"mutex_wait_us":235,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10752,"update_count":2000}
I20260812 06:19:04.236755  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=14.095187
I20260812 06:19:04.291451  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.055s	user 0.031s	sys 0.016s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22614,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:04.291911  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=2.188937
I20260812 06:19:04.303110  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4212,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:04.303524  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling MajorDeltaCompactionOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=1.000000
I20260812 06:19:04.480916  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: MajorDeltaCompactionOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.177s	user 0.121s	sys 0.048s 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":796,"lbm_read_time_us":9228,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27619,"lbm_writes_lt_1ms":543,"mutex_wait_us":19,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6528,"update_count":2500}
I20260812 06:19:04.481515  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=14.095187
I20260812 06:19:04.531694  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.050s	user 0.021s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20452,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:04.532194  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=2.188937
I20260812 06:19:04.547080  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.015s	user 0.004s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5776,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:04.547639  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling MajorDeltaCompactionOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=1.000000
I20260812 06:19:04.706530  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: MajorDeltaCompactionOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.158s	user 0.141s	sys 0.010s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":162,"lbm_read_time_us":8738,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31303,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":34560,"update_count":2500}
I20260812 06:19:04.707288  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=14.095187
I20260812 06:19:04.760010  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.053s	user 0.029s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21205,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:04.760516  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=2.188937
I20260812 06:19:04.775653  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.015s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5821,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:04.776105  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling FlushMRSOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=1.000000
I20260812 06:19:04.805217  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: FlushMRSOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.029s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":58,"dirs.run_cpu_time_us":188,"dirs.run_wall_time_us":1415,"drs_written":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1501,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:04.806077  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling LogGCOp(2e39ec36a3694bf5a2769f406d8d2896): free 124257457 bytes of WAL
I20260812 06:19:04.806331  3151 log_reader.cc:385] T 2e39ec36a3694bf5a2769f406d8d2896: removed 12 log segments from log reader
I20260812 06:19:04.806413  3151 log.cc:1079] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/2e39ec36a3694bf5a2769f406d8d2896/wal-000000027 (ops 129-133)
I20260812 06:19:04.806466  3151 log.cc:1079] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/2e39ec36a3694bf5a2769f406d8d2896/wal-000000028 (ops 134-138)
I20260812 06:19:04.806524  3151 log.cc:1079] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/2e39ec36a3694bf5a2769f406d8d2896/wal-000000029 (ops 139-143)
I20260812 06:19:04.806571  3151 log.cc:1079] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/2e39ec36a3694bf5a2769f406d8d2896/wal-000000030 (ops 144-148)
I20260812 06:19:04.806609  3151 log.cc:1079] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/2e39ec36a3694bf5a2769f406d8d2896/wal-000000031 (ops 149-153)
I20260812 06:19:04.806650  3151 log.cc:1079] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/2e39ec36a3694bf5a2769f406d8d2896/wal-000000032 (ops 154-158)
I20260812 06:19:04.806690  3151 log.cc:1079] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/2e39ec36a3694bf5a2769f406d8d2896/wal-000000033 (ops 159-163)
I20260812 06:19:04.806730  3151 log.cc:1079] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/2e39ec36a3694bf5a2769f406d8d2896/wal-000000034 (ops 164-168)
I20260812 06:19:04.806770  3151 log.cc:1079] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/2e39ec36a3694bf5a2769f406d8d2896/wal-000000035 (ops 169-173)
I20260812 06:19:04.806810  3151 log.cc:1079] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/2e39ec36a3694bf5a2769f406d8d2896/wal-000000036 (ops 174-178)
I20260812 06:19:04.806859  3151 log.cc:1079] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/2e39ec36a3694bf5a2769f406d8d2896/wal-000000037 (ops 179-182)
I20260812 06:19:04.806901  3151 log.cc:1079] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/2e39ec36a3694bf5a2769f406d8d2896/wal-000000038 (ops 183-187)
I20260812 06:19:04.834271  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: LogGCOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.028s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:19:04.834679  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=3.181125
I20260812 06:19:04.857111  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.022s	user 0.010s	sys 0.009s Metrics: {"bytes_written":5251342,"delete_count":0,"lbm_write_time_us":5211,"lbm_writes_lt_1ms":131,"mutex_wait_us":45,"reinsert_count":0,"update_count":640}
I20260812 06:19:04.857498  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=1.196750
I20260812 06:19:04.865132  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.007s	user 0.006s	sys 0.000s Metrics: {"bytes_written":2953955,"delete_count":0,"lbm_write_time_us":2877,"lbm_writes_lt_1ms":75,"reinsert_count":0,"update_count":360}
I20260812 06:19:04.865505  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling UndoDeltaBlockGCOp(2e39ec36a3694bf5a2769f406d8d2896): 482 bytes on disk
I20260812 06:19:04.865873  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: UndoDeltaBlockGCOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4}
I20260812 06:19:04.866318  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling MajorDeltaCompactionOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=1.000000
I20260812 06:19:05.067204  3032 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.540s	user 1.693s	sys 0.108s
I20260812 06:19:05.106554  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: MajorDeltaCompactionOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.240s	user 0.140s	sys 0.099s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979723,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":17469,"lbm_reads_lt_1ms":770,"lbm_write_time_us":42244,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"update_count":3500}
I20260812 06:19:05.107077  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=14.095187
I20260812 06:19:05.148288  3032 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.080s	user 0.002s	sys 0.000s
I20260812 06:19:05.148950  3032 tablet_server.cc:179] TabletServer@127.2.246.1:0 shutting down...
I20260812 06:19:05.163342  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: FlushDeltaMemStoresOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.056s	user 0.019s	sys 0.035s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21217,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:05.164165  3215 maintenance_manager.cc:419] P 4aba991fedd5415ebd857baaf5ee7ae1: Scheduling MajorDeltaCompactionOp(2e39ec36a3694bf5a2769f406d8d2896): perf score=1.000000
I20260812 06:19:05.294436  3151 maintenance_manager.cc:643] P 4aba991fedd5415ebd857baaf5ee7ae1: MajorDeltaCompactionOp(2e39ec36a3694bf5a2769f406d8d2896) complete. Timing: real 0.130s	user 0.078s	sys 0.052s 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":363,"lbm_read_time_us":8947,"lbm_reads_lt_1ms":467,"lbm_write_time_us":21236,"lbm_writes_lt_1ms":443,"mutex_wait_us":74,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:05.295373  3032 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:05.295818  3032 tablet_replica.cc:333] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1: stopping tablet replica
I20260812 06:19:05.296077  3032 raft_consensus.cc:2243] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:05.296329  3032 raft_consensus.cc:2272] T 2e39ec36a3694bf5a2769f406d8d2896 P 4aba991fedd5415ebd857baaf5ee7ae1 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:05.302340  3032 tablet_server.cc:196] TabletServer@127.2.246.1:0 shutdown complete.
I20260812 06:19:05.336437  3032 master.cc:562] Master@127.2.246.62:42825 shutting down...
I20260812 06:19:05.340833  3032 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 84b2273b8eb64575b9a08a9186e593af [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:05.341018  3032 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 84b2273b8eb64575b9a08a9186e593af [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:05.341074  3032 tablet_replica.cc:333] T 00000000000000000000000000000000 P 84b2273b8eb64575b9a08a9186e593af: stopping tablet replica
I20260812 06:19:05.353410  3032 master.cc:584] Master@127.2.246.62:42825 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5157 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:05.445600  3032 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.2.246.62:38493
I20260812 06:19:05.446070  3032 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:05.448287  3252 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:05.448379  3032 server_base.cc:1061] running on GCE node
W20260812 06:19:05.448282  3249 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:05.448467  3250 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:05.448725  3032 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:05.448794  3032 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:05.448820  3032 hybrid_clock.cc:648] HybridClock initialized: now 1786515545448819 us; error 0 us; skew 500 ppm
I20260812 06:19:05.449771  3032 webserver.cc:533] Webserver started at http://127.2.246.62:43991/ using document root <none> and password file <none>
I20260812 06:19:05.449993  3032 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:05.450063  3032 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:05.450143  3032 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:05.450551  3032 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515540278960-3032-0/minicluster-data/master-0-root/instance:
uuid: "659326f5602348cc8f2d35738f6cca11"
format_stamp: "Formatted at 2026-08-12 06:19:05 on dist-test-slave-6nmv"
I20260812 06:19:05.452032  3032 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:19:05.452967  3259 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:05.453195  3032 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:05.453301  3032 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515540278960-3032-0/minicluster-data/master-0-root
uuid: "659326f5602348cc8f2d35738f6cca11"
format_stamp: "Formatted at 2026-08-12 06:19:05 on dist-test-slave-6nmv"
I20260812 06:19:05.453387  3032 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515540278960-3032-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515540278960-3032-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515540278960-3032-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:05.474002  3032 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:05.474387  3032 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:05.478446  3032 rpc_server.cc:307] RPC server started. Bound to: 127.2.246.62:38493
I20260812 06:19:05.480528  3321 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.2.246.62:38493 every 8 connection(s)
I20260812 06:19:05.481360  3322 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:05.494784  3322 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 659326f5602348cc8f2d35738f6cca11: Bootstrap starting.
I20260812 06:19:05.495637  3322 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 659326f5602348cc8f2d35738f6cca11: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:05.496670  3322 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 659326f5602348cc8f2d35738f6cca11: No bootstrap required, opened a new log
I20260812 06:19:05.497061  3322 raft_consensus.cc:359] T 00000000000000000000000000000000 P 659326f5602348cc8f2d35738f6cca11 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "659326f5602348cc8f2d35738f6cca11" member_type: VOTER }
I20260812 06:19:05.497182  3322 raft_consensus.cc:385] T 00000000000000000000000000000000 P 659326f5602348cc8f2d35738f6cca11 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:05.497241  3322 raft_consensus.cc:740] T 00000000000000000000000000000000 P 659326f5602348cc8f2d35738f6cca11 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 659326f5602348cc8f2d35738f6cca11, State: Initialized, Role: FOLLOWER
I20260812 06:19:05.497409  3322 consensus_queue.cc:260] T 00000000000000000000000000000000 P 659326f5602348cc8f2d35738f6cca11 [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: "659326f5602348cc8f2d35738f6cca11" member_type: VOTER }
I20260812 06:19:05.497510  3322 raft_consensus.cc:399] T 00000000000000000000000000000000 P 659326f5602348cc8f2d35738f6cca11 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:05.497553  3322 raft_consensus.cc:493] T 00000000000000000000000000000000 P 659326f5602348cc8f2d35738f6cca11 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:05.497607  3322 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 659326f5602348cc8f2d35738f6cca11 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:05.498390  3322 raft_consensus.cc:515] T 00000000000000000000000000000000 P 659326f5602348cc8f2d35738f6cca11 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "659326f5602348cc8f2d35738f6cca11" member_type: VOTER }
I20260812 06:19:05.498559  3322 leader_election.cc:304] T 00000000000000000000000000000000 P 659326f5602348cc8f2d35738f6cca11 [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: 659326f5602348cc8f2d35738f6cca11; no voters: 
I20260812 06:19:05.498767  3322 leader_election.cc:290] T 00000000000000000000000000000000 P 659326f5602348cc8f2d35738f6cca11 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:05.498905  3325 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 659326f5602348cc8f2d35738f6cca11 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:05.499167  3325 raft_consensus.cc:697] T 00000000000000000000000000000000 P 659326f5602348cc8f2d35738f6cca11 [term 1 LEADER]: Becoming Leader. State: Replica: 659326f5602348cc8f2d35738f6cca11, State: Running, Role: LEADER
I20260812 06:19:05.499262  3322 sys_catalog.cc:565] T 00000000000000000000000000000000 P 659326f5602348cc8f2d35738f6cca11 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:05.499318  3325 consensus_queue.cc:237] T 00000000000000000000000000000000 P 659326f5602348cc8f2d35738f6cca11 [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: "659326f5602348cc8f2d35738f6cca11" member_type: VOTER }
I20260812 06:19:05.499789  3326 sys_catalog.cc:455] T 00000000000000000000000000000000 P 659326f5602348cc8f2d35738f6cca11 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "659326f5602348cc8f2d35738f6cca11" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "659326f5602348cc8f2d35738f6cca11" member_type: VOTER } }
I20260812 06:19:05.499841  3327 sys_catalog.cc:455] T 00000000000000000000000000000000 P 659326f5602348cc8f2d35738f6cca11 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 659326f5602348cc8f2d35738f6cca11. Latest consensus state: current_term: 1 leader_uuid: "659326f5602348cc8f2d35738f6cca11" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "659326f5602348cc8f2d35738f6cca11" member_type: VOTER } }
I20260812 06:19:05.499882  3326 sys_catalog.cc:458] T 00000000000000000000000000000000 P 659326f5602348cc8f2d35738f6cca11 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:05.499938  3327 sys_catalog.cc:458] T 00000000000000000000000000000000 P 659326f5602348cc8f2d35738f6cca11 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:05.500465  3331 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:05.501475  3331 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:05.501698  3032 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:05.503394  3331 catalog_manager.cc:1383] Generated new cluster ID: 039da19d743740768ff9922db6464a57
I20260812 06:19:05.503458  3331 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:05.514235  3331 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:05.514763  3331 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:05.522795  3331 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 659326f5602348cc8f2d35738f6cca11: Generated new TSK 0
I20260812 06:19:05.522961  3331 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:05.534132  3032 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:05.535995  3346 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:05.536211  3032 server_base.cc:1061] running on GCE node
W20260812 06:19:05.536029  3343 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:05.535996  3344 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:05.536545  3032 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:05.536612  3032 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:05.536638  3032 hybrid_clock.cc:648] HybridClock initialized: now 1786515545536637 us; error 0 us; skew 500 ppm
I20260812 06:19:05.537577  3032 webserver.cc:533] Webserver started at http://127.2.246.1:37389/ using document root <none> and password file <none>
I20260812 06:19:05.537768  3032 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:05.537864  3032 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:05.537945  3032 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:05.538312  3032 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515540278960-3032-0/minicluster-data/ts-0-root/instance:
uuid: "b392c75445d44540851a46584ad59423"
format_stamp: "Formatted at 2026-08-12 06:19:05 on dist-test-slave-6nmv"
I20260812 06:19:05.539781  3032 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:05.540756  3351 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:05.541002  3032 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:05.541090  3032 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515540278960-3032-0/minicluster-data/ts-0-root
uuid: "b392c75445d44540851a46584ad59423"
format_stamp: "Formatted at 2026-08-12 06:19:05 on dist-test-slave-6nmv"
I20260812 06:19:05.541173  3032 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515540278960-3032-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515540278960-3032-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515540278960-3032-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:05.555661  3032 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:05.555984  3032 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:05.556259  3032 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:05.556686  3032 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:05.556744  3032 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:05.556803  3032 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:05.556836  3032 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:05.561010  3032 rpc_server.cc:307] RPC server started. Bound to: 127.2.246.1:43693
I20260812 06:19:05.561043  3428 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.2.246.1:43693 every 8 connection(s)
I20260812 06:19:05.568912  3430 heartbeater.cc:344] Connected to a master server at 127.2.246.62:38493
I20260812 06:19:05.569015  3430 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:05.569239  3430 heartbeater.cc:507] Master 127.2.246.62:38493 requested a full tablet report, sending...
I20260812 06:19:05.569861  3277 ts_manager.cc:194] Registered new tserver with Master: b392c75445d44540851a46584ad59423 (127.2.246.1:43693)
I20260812 06:19:05.570189  3032 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.008760057s
I20260812 06:19:05.570641  3277 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:36228
I20260812 06:19:05.576714  3277 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:36238:
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:05.585348  3387 tablet_service.cc:1511] Processing CreateTablet for tablet cce17bf5851147a1b6995162c1a4048d (DEFAULT_TABLE table=heavy-update-compaction-test [id=de8c0462fb2a47738eae9500309a9185]), partition=
I20260812 06:19:05.585589  3387 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet cce17bf5851147a1b6995162c1a4048d. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:05.587577  3442 tablet_bootstrap.cc:492] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423: Bootstrap starting.
I20260812 06:19:05.588369  3442 tablet_bootstrap.cc:654] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:05.589347  3442 tablet_bootstrap.cc:492] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423: No bootstrap required, opened a new log
I20260812 06:19:05.589440  3442 ts_tablet_manager.cc:1403] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:19:05.589879  3442 raft_consensus.cc:359] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b392c75445d44540851a46584ad59423" member_type: VOTER last_known_addr { host: "127.2.246.1" port: 43693 } }
I20260812 06:19:05.589970  3442 raft_consensus.cc:385] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:05.590024  3442 raft_consensus.cc:740] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: b392c75445d44540851a46584ad59423, State: Initialized, Role: FOLLOWER
I20260812 06:19:05.590224  3442 consensus_queue.cc:260] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423 [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: "b392c75445d44540851a46584ad59423" member_type: VOTER last_known_addr { host: "127.2.246.1" port: 43693 } }
I20260812 06:19:05.590332  3442 raft_consensus.cc:399] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:05.590394  3442 raft_consensus.cc:493] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:05.590457  3442 raft_consensus.cc:3060] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:05.591214  3442 raft_consensus.cc:515] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b392c75445d44540851a46584ad59423" member_type: VOTER last_known_addr { host: "127.2.246.1" port: 43693 } }
I20260812 06:19:05.591321  3442 leader_election.cc:304] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423 [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: b392c75445d44540851a46584ad59423; no voters: 
I20260812 06:19:05.591459  3442 leader_election.cc:290] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:05.591575  3444 raft_consensus.cc:2804] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:05.591818  3444 raft_consensus.cc:697] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423 [term 1 LEADER]: Becoming Leader. State: Replica: b392c75445d44540851a46584ad59423, State: Running, Role: LEADER
I20260812 06:19:05.591881  3442 ts_tablet_manager.cc:1434] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:19:05.591912  3430 heartbeater.cc:499] Master 127.2.246.62:38493 was elected leader, sending a full tablet report...
I20260812 06:19:05.592023  3444 consensus_queue.cc:237] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423 [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: "b392c75445d44540851a46584ad59423" member_type: VOTER last_known_addr { host: "127.2.246.1" port: 43693 } }
I20260812 06:19:05.593230  3277 catalog_manager.cc:5719] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423 reported cstate change: term changed from 0 to 1, leader changed from <none> to b392c75445d44540851a46584ad59423 (127.2.246.1). New cstate: current_term: 1 leader_uuid: "b392c75445d44540851a46584ad59423" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b392c75445d44540851a46584ad59423" member_type: VOTER last_known_addr { host: "127.2.246.1" port: 43693 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:05.649602  3032 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.049s	user 0.013s	sys 0.008s
I20260812 06:19:05.811856  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling FlushMRSOp(cce17bf5851147a1b6995162c1a4048d): perf score=23.023690
I20260812 06:19:05.963982  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: FlushMRSOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.152s	user 0.109s	sys 0.040s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":57,"dirs.run_cpu_time_us":210,"dirs.run_wall_time_us":832,"drs_written":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4,"lbm_write_time_us":42107,"lbm_writes_lt_1ms":857,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"spinlock_wait_cycles":8832,"update_count":1500}
I20260812 06:19:05.964563  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling LogGCOp(cce17bf5851147a1b6995162c1a4048d): free 20743880 bytes of WAL
I20260812 06:19:05.964761  3356 log_reader.cc:385] T cce17bf5851147a1b6995162c1a4048d: removed 2 log segments from log reader
I20260812 06:19:05.964802  3356 log.cc:1079] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/cce17bf5851147a1b6995162c1a4048d/wal-000000001 (ops 1-6)
I20260812 06:19:05.964828  3356 log.cc:1079] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/cce17bf5851147a1b6995162c1a4048d/wal-000000002 (ops 7-11)
I20260812 06:19:05.969758  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: LogGCOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.005s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:19:05.970266  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d): perf score=2.188937
I20260812 06:19:06.000208  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.030s	user 0.012s	sys 0.002s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5126,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:06.000691  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d): perf score=2.188937
I20260812 06:19:06.011039  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4047,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:06.011735  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling UndoDeltaBlockGCOp(cce17bf5851147a1b6995162c1a4048d): 20513821 bytes on disk
I20260812 06:19:06.012305  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: UndoDeltaBlockGCOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4}
I20260812 06:19:06.012713  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling MajorDeltaCompactionOp(cce17bf5851147a1b6995162c1a4048d): perf score=1.000000
I20260812 06:19:06.186233  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: MajorDeltaCompactionOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.173s	user 0.092s	sys 0.081s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815802,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":497,"lbm_read_time_us":11561,"lbm_reads_lt_1ms":569,"lbm_write_time_us":27855,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13184,"thread_start_us":350,"threads_started":5,"update_count":2500}
I20260812 06:19:06.186846  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d): perf score=14.095187
I20260812 06:19:06.231295  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.044s	user 0.021s	sys 0.022s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19624,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:06.231937  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d): perf score=2.188937
I20260812 06:19:06.254750  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.023s	user 0.007s	sys 0.015s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4655,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:06.255162  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling MajorDeltaCompactionOp(cce17bf5851147a1b6995162c1a4048d): perf score=1.000000
I20260812 06:19:06.430907  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: MajorDeltaCompactionOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.176s	user 0.110s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":350,"lbm_read_time_us":11700,"lbm_reads_lt_1ms":564,"lbm_write_time_us":28049,"lbm_writes_lt_1ms":543,"mutex_wait_us":84,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:19:06.431668  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d): perf score=15.087375
I20260812 06:19:06.480501  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.049s	user 0.026s	sys 0.020s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":21423,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:19:06.481037  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d): perf score=2.188937
I20260812 06:19:06.508912  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.028s	user 0.005s	sys 0.014s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4641,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:06.509344  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d): perf score=2.188937
I20260812 06:19:06.519618  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4091,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:06.520002  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling MajorDeltaCompactionOp(cce17bf5851147a1b6995162c1a4048d): perf score=1.000000
I20260812 06:19:06.726068  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: MajorDeltaCompactionOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.206s	user 0.154s	sys 0.047s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918201,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":394,"lbm_read_time_us":14029,"lbm_reads_lt_1ms":673,"lbm_write_time_us":32648,"lbm_writes_lt_1ms":643,"mutex_wait_us":2,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6144,"update_count":3000}
I20260812 06:19:06.726678  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d): perf score=15.087375
I20260812 06:19:06.784313  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.057s	user 0.026s	sys 0.026s Metrics: {"bytes_written":16820144,"delete_count":0,"lbm_write_time_us":19375,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":412,"reinsert_count":0,"update_count":2050}
I20260812 06:19:06.784857  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d): perf score=5.165500
I20260812 06:19:06.800832  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.016s	user 0.010s	sys 0.003s Metrics: {"bytes_written":6851281,"delete_count":0,"lbm_write_time_us":6882,"lbm_writes_lt_1ms":170,"reinsert_count":0,"update_count":835}
I20260812 06:19:06.801298  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling MajorDeltaCompactionOp(cce17bf5851147a1b6995162c1a4048d): perf score=1.000000
I20260812 06:19:07.004856  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: MajorDeltaCompactionOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.203s	user 0.151s	sys 0.052s Metrics: {"cfile_cache_miss":609,"cfile_cache_miss_bytes":27974542,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":203,"lbm_read_time_us":15986,"lbm_reads_lt_1ms":645,"lbm_write_time_us":31676,"lbm_writes_lt_1ms":620,"mutex_wait_us":25,"peak_mem_usage":72517899,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":2885}
I20260812 06:19:07.005533  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d): perf score=15.087375
I20260812 06:19:07.068506  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.063s	user 0.029s	sys 0.031s Metrics: {"bytes_written":17353457,"delete_count":0,"lbm_write_time_us":25147,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":424,"reinsert_count":0,"update_count":2115}
I20260812 06:19:07.069121  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d): perf score=2.188937
I20260812 06:19:07.086876  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.018s	user 0.013s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6933,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:07.087484  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling MajorDeltaCompactionOp(cce17bf5851147a1b6995162c1a4048d): perf score=1.000000
I20260812 06:19:07.261562  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: MajorDeltaCompactionOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.174s	user 0.118s	sys 0.056s Metrics: {"cfile_cache_miss":555,"cfile_cache_miss_bytes":25759239,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":450,"lbm_read_time_us":11633,"lbm_reads_lt_1ms":595,"lbm_write_time_us":30039,"lbm_writes_lt_1ms":566,"mutex_wait_us":26,"peak_mem_usage":65100089,"reinsert_count":0,"spinlock_wait_cycles":11392,"update_count":2615}
I20260812 06:19:07.262367  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d): perf score=14.095187
I20260812 06:19:07.318712  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.056s	user 0.025s	sys 0.030s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19819,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:07.319276  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d): perf score=2.188937
I20260812 06:19:07.329713  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4060,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:07.330229  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling FlushMRSOp(cce17bf5851147a1b6995162c1a4048d): perf score=1.000000
I20260812 06:19:07.365689  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: FlushMRSOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.035s	user 0.034s	sys 0.000s Metrics: {"bytes_written":1316413,"cfile_init":1,"dirs.queue_time_us":59,"dirs.run_cpu_time_us":195,"dirs.run_wall_time_us":1525,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1751,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:19:07.366343  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling LogGCOp(cce17bf5851147a1b6995162c1a4048d): free 132571309 bytes of WAL
I20260812 06:19:07.366567  3356 log_reader.cc:385] T cce17bf5851147a1b6995162c1a4048d: removed 13 log segments from log reader
I20260812 06:19:07.366628  3356 log.cc:1079] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/cce17bf5851147a1b6995162c1a4048d/wal-000000003 (ops 12-16)
I20260812 06:19:07.366676  3356 log.cc:1079] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/cce17bf5851147a1b6995162c1a4048d/wal-000000004 (ops 17-21)
I20260812 06:19:07.366729  3356 log.cc:1079] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/cce17bf5851147a1b6995162c1a4048d/wal-000000005 (ops 22-26)
I20260812 06:19:07.366767  3356 log.cc:1079] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/cce17bf5851147a1b6995162c1a4048d/wal-000000006 (ops 27-31)
I20260812 06:19:07.366802  3356 log.cc:1079] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/cce17bf5851147a1b6995162c1a4048d/wal-000000007 (ops 32-36)
I20260812 06:19:07.366837  3356 log.cc:1079] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/cce17bf5851147a1b6995162c1a4048d/wal-000000008 (ops 37-41)
I20260812 06:19:07.366871  3356 log.cc:1079] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/cce17bf5851147a1b6995162c1a4048d/wal-000000009 (ops 42-46)
I20260812 06:19:07.366909  3356 log.cc:1079] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/cce17bf5851147a1b6995162c1a4048d/wal-000000010 (ops 47-51)
I20260812 06:19:07.366943  3356 log.cc:1079] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/cce17bf5851147a1b6995162c1a4048d/wal-000000011 (ops 52-56)
I20260812 06:19:07.366978  3356 log.cc:1079] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/cce17bf5851147a1b6995162c1a4048d/wal-000000012 (ops 57-60)
I20260812 06:19:07.367012  3356 log.cc:1079] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/cce17bf5851147a1b6995162c1a4048d/wal-000000013 (ops 61-65)
I20260812 06:19:07.367048  3356 log.cc:1079] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/cce17bf5851147a1b6995162c1a4048d/wal-000000014 (ops 66-70)
I20260812 06:19:07.367082  3356 log.cc:1079] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/cce17bf5851147a1b6995162c1a4048d/wal-000000015 (ops 71-74)
I20260812 06:19:07.396567  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: LogGCOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.030s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:19:07.397080  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling UndoDeltaBlockGCOp(cce17bf5851147a1b6995162c1a4048d): 493 bytes on disk
I20260812 06:19:07.397547  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: UndoDeltaBlockGCOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4}
I20260812 06:19:07.398119  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d): perf score=3.181125
I20260812 06:19:07.416486  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.018s	user 0.006s	sys 0.009s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":7238,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:07.416836  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d): perf score=2.188937
I20260812 06:19:07.425575  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3522,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:07.425938  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling MajorDeltaCompactionOp(cce17bf5851147a1b6995162c1a4048d): perf score=1.000000
I20260812 06:19:07.640770  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: MajorDeltaCompactionOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.215s	user 0.134s	sys 0.077s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020733,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":272,"lbm_read_time_us":14244,"lbm_reads_lt_1ms":774,"lbm_write_time_us":39445,"lbm_writes_lt_1ms":743,"mutex_wait_us":21,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":7552,"thread_start_us":75,"threads_started":1,"update_count":3500}
I20260812 06:19:07.641264  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d): perf score=18.063937
I20260812 06:19:07.695250  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.054s	user 0.033s	sys 0.019s Metrics: {"bytes_written":20512321,"delete_count":0,"lbm_write_time_us":24263,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:07.695825  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d): perf score=2.188937
I20260812 06:19:07.713552  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.018s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6937,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:07.714071  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling MajorDeltaCompactionOp(cce17bf5851147a1b6995162c1a4048d): perf score=1.000000
I20260812 06:19:07.887800  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: MajorDeltaCompactionOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.174s	user 0.148s	sys 0.025s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918103,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":2017,"lbm_read_time_us":12081,"lbm_reads_lt_1ms":672,"lbm_write_time_us":35995,"lbm_writes_lt_1ms":643,"mutex_wait_us":782,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":5120,"update_count":3000}
I20260812 06:19:07.889041  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d): perf score=14.095187
I20260812 06:19:07.947554  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.058s	user 0.041s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":26492,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:07.948101  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d): perf score=2.188937
I20260812 06:19:07.960160  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4772,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:07.960692  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling MajorDeltaCompactionOp(cce17bf5851147a1b6995162c1a4048d): perf score=1.000000
I20260812 06:19:08.116458  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: MajorDeltaCompactionOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.156s	user 0.117s	sys 0.037s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":192,"lbm_read_time_us":9373,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33410,"lbm_writes_lt_1ms":543,"mutex_wait_us":43,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12160,"update_count":2500}
I20260812 06:19:08.117059  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d): perf score=12.110812
I20260812 06:19:08.159976  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.043s	user 0.033s	sys 0.007s Metrics: {"bytes_written":13538208,"delete_count":0,"lbm_write_time_us":18795,"lbm_writes_lt_1ms":333,"reinsert_count":0,"update_count":1650}
I20260812 06:19:08.160631  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d): perf score=1.196750
I20260812 06:19:08.178220  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.015s	user 0.011s	sys 0.001s Metrics: {"bytes_written":2871905,"delete_count":0,"lbm_write_time_us":4686,"lbm_writes_lt_1ms":73,"reinsert_count":0,"update_count":350}
I20260812 06:19:08.178628  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling MajorDeltaCompactionOp(cce17bf5851147a1b6995162c1a4048d): perf score=1.000000
I20260812 06:19:08.326714  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: MajorDeltaCompactionOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.148s	user 0.116s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713236,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":193,"lbm_read_time_us":10076,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23196,"lbm_writes_lt_1ms":443,"mutex_wait_us":18,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2000}
I20260812 06:19:08.327283  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d): perf score=14.095187
I20260812 06:19:08.374105  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.047s	user 0.032s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19289,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:08.374644  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d): perf score=2.188937
I20260812 06:19:08.396235  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.021s	user 0.008s	sys 0.011s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4293,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:08.396742  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling MajorDeltaCompactionOp(cce17bf5851147a1b6995162c1a4048d): perf score=1.000000
I20260812 06:19:08.569072  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: MajorDeltaCompactionOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.172s	user 0.098s	sys 0.073s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":810,"lbm_read_time_us":12685,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27824,"lbm_writes_lt_1ms":543,"mutex_wait_us":378,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4224,"update_count":2500}
I20260812 06:19:08.569667  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d): perf score=14.095187
I20260812 06:19:08.629530  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.060s	user 0.027s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24132,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:08.630041  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d): perf score=2.188937
I20260812 06:19:08.640707  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.011s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4059,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:08.641134  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling MajorDeltaCompactionOp(cce17bf5851147a1b6995162c1a4048d): perf score=1.000000
I20260812 06:19:08.837152  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: MajorDeltaCompactionOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.196s	user 0.118s	sys 0.065s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":287,"lbm_read_time_us":10200,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33823,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2500}
I20260812 06:19:08.837908  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d): perf score=14.095187
I20260812 06:19:08.885766  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.048s	user 0.022s	sys 0.017s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18715,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:08.886270  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d): perf score=2.188937
I20260812 06:19:08.896493  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3956,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:08.897001  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling FlushMRSOp(cce17bf5851147a1b6995162c1a4048d): perf score=1.000000
I20260812 06:19:08.923626  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: FlushMRSOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.026s	user 0.020s	sys 0.004s Metrics: {"bytes_written":1316418,"cfile_init":1,"dirs.queue_time_us":83,"dirs.run_cpu_time_us":223,"dirs.run_wall_time_us":1479,"drs_written":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1520,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:19:08.924330  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling LogGCOp(cce17bf5851147a1b6995162c1a4048d): free 133024416 bytes of WAL
I20260812 06:19:08.924600  3356 log_reader.cc:385] T cce17bf5851147a1b6995162c1a4048d: removed 13 log segments from log reader
I20260812 06:19:08.924659  3356 log.cc:1079] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/cce17bf5851147a1b6995162c1a4048d/wal-000000016 (ops 75-79)
I20260812 06:19:08.924698  3356 log.cc:1079] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/cce17bf5851147a1b6995162c1a4048d/wal-000000017 (ops 80-84)
I20260812 06:19:08.924726  3356 log.cc:1079] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/cce17bf5851147a1b6995162c1a4048d/wal-000000018 (ops 85-89)
I20260812 06:19:08.924753  3356 log.cc:1079] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/cce17bf5851147a1b6995162c1a4048d/wal-000000019 (ops 90-94)
I20260812 06:19:08.924774  3356 log.cc:1079] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/cce17bf5851147a1b6995162c1a4048d/wal-000000020 (ops 95-99)
I20260812 06:19:08.924805  3356 log.cc:1079] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/cce17bf5851147a1b6995162c1a4048d/wal-000000021 (ops 100-104)
I20260812 06:19:08.924837  3356 log.cc:1079] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/cce17bf5851147a1b6995162c1a4048d/wal-000000022 (ops 105-109)
I20260812 06:19:08.924870  3356 log.cc:1079] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/cce17bf5851147a1b6995162c1a4048d/wal-000000023 (ops 110-114)
I20260812 06:19:08.924896  3356 log.cc:1079] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/cce17bf5851147a1b6995162c1a4048d/wal-000000024 (ops 115-119)
I20260812 06:19:08.924923  3356 log.cc:1079] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/cce17bf5851147a1b6995162c1a4048d/wal-000000025 (ops 120-124)
I20260812 06:19:08.924944  3356 log.cc:1079] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/cce17bf5851147a1b6995162c1a4048d/wal-000000026 (ops 125-129)
I20260812 06:19:08.924973  3356 log.cc:1079] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/cce17bf5851147a1b6995162c1a4048d/wal-000000027 (ops 130-134)
I20260812 06:19:08.925004  3356 log.cc:1079] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/cce17bf5851147a1b6995162c1a4048d/wal-000000028 (ops 135-138)
I20260812 06:19:08.958567  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: LogGCOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.034s	user 0.000s	sys 0.033s Metrics: {}
I20260812 06:19:08.959012  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling UndoDeltaBlockGCOp(cce17bf5851147a1b6995162c1a4048d): 492 bytes on disk
I20260812 06:19:08.959687  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: UndoDeltaBlockGCOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":117,"lbm_reads_lt_1ms":4}
I20260812 06:19:08.960316  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d): perf score=2.188937
I20260812 06:19:08.988128  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.028s	user 0.004s	sys 0.013s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6105,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:08.988664  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d): perf score=2.188937
I20260812 06:19:08.998596  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.010s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3998,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:08.998955  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling MajorDeltaCompactionOp(cce17bf5851147a1b6995162c1a4048d): perf score=1.000000
I20260812 06:19:09.252172  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: MajorDeltaCompactionOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.253s	user 0.146s	sys 0.097s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020744,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":174,"lbm_read_time_us":15257,"lbm_reads_lt_1ms":774,"lbm_write_time_us":39723,"lbm_writes_lt_1ms":743,"mutex_wait_us":26,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1792,"thread_start_us":69,"threads_started":1,"update_count":3500}
I20260812 06:19:09.252686  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d): perf score=18.063937
I20260812 06:19:09.323354  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.070s	user 0.032s	sys 0.027s Metrics: {"bytes_written":20512320,"delete_count":0,"lbm_write_time_us":27659,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:09.323843  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d): perf score=2.188937
I20260812 06:19:09.334319  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3899,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:09.334894  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling MajorDeltaCompactionOp(cce17bf5851147a1b6995162c1a4048d): perf score=1.000000
I20260812 06:19:09.537066  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: MajorDeltaCompactionOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.202s	user 0.126s	sys 0.072s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918102,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":294,"lbm_read_time_us":12471,"lbm_reads_lt_1ms":672,"lbm_write_time_us":32276,"lbm_writes_lt_1ms":643,"mutex_wait_us":116,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":3000}
I20260812 06:19:09.537994  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d): perf score=16.079562
I20260812 06:19:09.608556  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.070s	user 0.029s	sys 0.026s Metrics: {"bytes_written":17681651,"delete_count":0,"lbm_write_time_us":24818,"lbm_writes_lt_1ms":434,"reinsert_count":0,"update_count":2155}
I20260812 06:19:09.609004  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d): perf score=5.165500
I20260812 06:19:09.629410  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.020s	user 0.014s	sys 0.003s Metrics: {"bytes_written":6933333,"delete_count":0,"lbm_write_time_us":7806,"lbm_writes_lt_1ms":172,"reinsert_count":0,"update_count":845}
I20260812 06:19:09.629966  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling MajorDeltaCompactionOp(cce17bf5851147a1b6995162c1a4048d): perf score=1.000000
I20260812 06:19:09.831306  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: MajorDeltaCompactionOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.201s	user 0.149s	sys 0.052s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918101,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":196,"lbm_read_time_us":15519,"lbm_reads_lt_1ms":672,"lbm_write_time_us":33837,"lbm_writes_lt_1ms":643,"mutex_wait_us":36,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":55552,"update_count":3000}
I20260812 06:19:09.836212  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d): perf score=18.063937
I20260812 06:19:09.892267  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.056s	user 0.046s	sys 0.004s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":24316,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:09.892784  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d): perf score=2.188937
I20260812 06:19:09.903352  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4005,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:09.903806  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling MajorDeltaCompactionOp(cce17bf5851147a1b6995162c1a4048d): perf score=1.000000
I20260812 06:19:10.104597  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: MajorDeltaCompactionOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.201s	user 0.153s	sys 0.047s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918098,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":334,"lbm_read_time_us":12693,"lbm_reads_lt_1ms":672,"lbm_write_time_us":31945,"lbm_writes_lt_1ms":643,"mutex_wait_us":39,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":8448,"update_count":3000}
I20260812 06:19:10.105276  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d): perf score=18.063937
I20260812 06:19:10.163033  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.058s	user 0.030s	sys 0.024s Metrics: {"bytes_written":20512313,"delete_count":0,"lbm_write_time_us":25490,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:10.163579  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling MajorDeltaCompactionOp(cce17bf5851147a1b6995162c1a4048d): perf score=1.000000
I20260812 06:19:10.339493  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: MajorDeltaCompactionOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.176s	user 0.103s	sys 0.072s Metrics: {"cfile_cache_miss":531,"cfile_cache_miss_bytes":24815564,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":573,"lbm_read_time_us":11733,"lbm_reads_lt_1ms":563,"lbm_write_time_us":28452,"lbm_writes_lt_1ms":543,"mutex_wait_us":377,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2500}
I20260812 06:19:10.342232  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d): perf score=14.095187
I20260812 06:19:10.399501  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.057s	user 0.030s	sys 0.025s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20312,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:10.400040  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d): perf score=2.188937
I20260812 06:19:10.417057  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.017s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6690,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:10.417518  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling FlushMRSOp(cce17bf5851147a1b6995162c1a4048d): perf score=1.000000
I20260812 06:19:10.451385  3032 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.802s	user 1.779s	sys 0.157s
I20260812 06:19:10.453474  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: FlushMRSOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.036s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1234477,"cfile_init":1,"dirs.queue_time_us":58,"dirs.run_cpu_time_us":269,"dirs.run_wall_time_us":1355,"drs_written":1,"lbm_read_time_us":82,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1617,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:10.454277  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling LogGCOp(cce17bf5851147a1b6995162c1a4048d): free 121006700 bytes of WAL
I20260812 06:19:10.454511  3356 log_reader.cc:385] T cce17bf5851147a1b6995162c1a4048d: removed 12 log segments from log reader
I20260812 06:19:10.454576  3356 log.cc:1079] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/cce17bf5851147a1b6995162c1a4048d/wal-000000029 (ops 139-143)
I20260812 06:19:10.454622  3356 log.cc:1079] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/cce17bf5851147a1b6995162c1a4048d/wal-000000030 (ops 144-148)
I20260812 06:19:10.454663  3356 log.cc:1079] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/cce17bf5851147a1b6995162c1a4048d/wal-000000031 (ops 149-153)
I20260812 06:19:10.454711  3356 log.cc:1079] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/cce17bf5851147a1b6995162c1a4048d/wal-000000032 (ops 154-158)
I20260812 06:19:10.454746  3356 log.cc:1079] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/cce17bf5851147a1b6995162c1a4048d/wal-000000033 (ops 159-163)
I20260812 06:19:10.454780  3356 log.cc:1079] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/cce17bf5851147a1b6995162c1a4048d/wal-000000034 (ops 164-168)
I20260812 06:19:10.454813  3356 log.cc:1079] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/cce17bf5851147a1b6995162c1a4048d/wal-000000035 (ops 169-172)
I20260812 06:19:10.454846  3356 log.cc:1079] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/cce17bf5851147a1b6995162c1a4048d/wal-000000036 (ops 173-177)
I20260812 06:19:10.454880  3356 log.cc:1079] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/cce17bf5851147a1b6995162c1a4048d/wal-000000037 (ops 178-182)
I20260812 06:19:10.454913  3356 log.cc:1079] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/cce17bf5851147a1b6995162c1a4048d/wal-000000038 (ops 183-187)
I20260812 06:19:10.454947  3356 log.cc:1079] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/cce17bf5851147a1b6995162c1a4048d/wal-000000039 (ops 188-192)
I20260812 06:19:10.454977  3356 log.cc:1079] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423: Deleting log segment in path: /tmp/dist-test-taskG0qsLZ/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515540278960-3032-0/minicluster-data/ts-0-root/wals/cce17bf5851147a1b6995162c1a4048d/wal-000000040 (ops 193-197)
I20260812 06:19:10.476454  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: LogGCOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.022s	user 0.000s	sys 0.019s Metrics: {}
I20260812 06:19:10.476797  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling UndoDeltaBlockGCOp(cce17bf5851147a1b6995162c1a4048d): 473 bytes on disk
I20260812 06:19:10.477164  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: UndoDeltaBlockGCOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4}
I20260812 06:19:10.477627  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d): perf score=2.188937
I20260812 06:19:10.486748  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: FlushDeltaMemStoresOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3829,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:10.487063  3431 maintenance_manager.cc:419] P b392c75445d44540851a46584ad59423: Scheduling MajorDeltaCompactionOp(cce17bf5851147a1b6995162c1a4048d): perf score=1.000000
I20260812 06:19:10.518770  3032 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.067s	user 0.003s	sys 0.000s
I20260812 06:19:10.519317  3032 tablet_server.cc:179] TabletServer@127.2.246.1:0 shutting down...
I20260812 06:19:10.625011  3356 maintenance_manager.cc:643] P b392c75445d44540851a46584ad59423: MajorDeltaCompactionOp(cce17bf5851147a1b6995162c1a4048d) complete. Timing: real 0.138s	user 0.081s	sys 0.057s Metrics: {"cfile_cache_hit":502,"cfile_cache_hit_bytes":20512299,"cfile_cache_miss":131,"cfile_cache_miss_bytes":8405916,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":725,"lbm_read_time_us":4131,"lbm_reads_lt_1ms":163,"lbm_write_time_us":29605,"lbm_writes_lt_1ms":643,"mutex_wait_us":22,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":95872,"thread_start_us":76,"threads_started":1,"update_count":3000}
I20260812 06:19:10.625988  3032 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:10.626364  3032 tablet_replica.cc:333] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423: stopping tablet replica
I20260812 06:19:10.626528  3032 raft_consensus.cc:2243] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:10.626744  3032 raft_consensus.cc:2272] T cce17bf5851147a1b6995162c1a4048d P b392c75445d44540851a46584ad59423 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:10.640112  3032 tablet_server.cc:196] TabletServer@127.2.246.1:0 shutdown complete.
I20260812 06:19:10.678911  3032 master.cc:562] Master@127.2.246.62:38493 shutting down...
I20260812 06:19:10.682565  3032 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 659326f5602348cc8f2d35738f6cca11 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:10.682747  3032 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 659326f5602348cc8f2d35738f6cca11 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:10.682822  3032 tablet_replica.cc:333] T 00000000000000000000000000000000 P 659326f5602348cc8f2d35738f6cca11: stopping tablet replica
I20260812 06:19:10.694788  3032 master.cc:584] Master@127.2.246.62:38493 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5337 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10496 ms total)

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