[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:18:34.761703 14921 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.14.146.126:32773
I20260812 06:18:34.762892 14921 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:18:34.763551 14921 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:34.770107 14933 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:34.770119 14938 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:34.770283 14921 server_base.cc:1061] running on GCE node
W20260812 06:18:34.770489 14932 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:34.771072 14921 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:34.771221 14921 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:34.771286 14921 hybrid_clock.cc:648] HybridClock initialized: now 1786515514771282 us; error 0 us; skew 500 ppm
I20260812 06:18:34.773214 14921 webserver.cc:533] Webserver started at http://127.14.146.126:44293/ using document root <none> and password file <none>
I20260812 06:18:34.773850 14921 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:34.773953 14921 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:34.774240 14921 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:34.776129 14921 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514750243-14921-0/minicluster-data/master-0-root/instance:
uuid: "d90713e87fef46fca00e0ee426635d23"
format_stamp: "Formatted at 2026-08-12 06:18:34 on dist-test-slave-twwt"
I20260812 06:18:34.780058 14921 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.003s	sys 0.002s
I20260812 06:18:34.782377 14948 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:34.783628 14921 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:34.783785 14921 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514750243-14921-0/minicluster-data/master-0-root
uuid: "d90713e87fef46fca00e0ee426635d23"
format_stamp: "Formatted at 2026-08-12 06:18:34 on dist-test-slave-twwt"
I20260812 06:18:34.783912 14921 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514750243-14921-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514750243-14921-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514750243-14921-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:34.815270 14921 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:34.816038 14921 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:18:34.816236 14921 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:34.824404 14921 rpc_server.cc:307] RPC server started. Bound to: 127.14.146.126:32773
I20260812 06:18:34.824412 15036 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.14.146.126:32773 every 8 connection(s)
I20260812 06:18:34.826990 15037 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:34.833034 15037 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P d90713e87fef46fca00e0ee426635d23: Bootstrap starting.
I20260812 06:18:34.835638 15037 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P d90713e87fef46fca00e0ee426635d23: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:34.836627 15037 log.cc:826] T 00000000000000000000000000000000 P d90713e87fef46fca00e0ee426635d23: Log is configured to *not* fsync() on all Append() calls
I20260812 06:18:34.838511 15037 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P d90713e87fef46fca00e0ee426635d23: No bootstrap required, opened a new log
I20260812 06:18:34.841437 15037 raft_consensus.cc:359] T 00000000000000000000000000000000 P d90713e87fef46fca00e0ee426635d23 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d90713e87fef46fca00e0ee426635d23" member_type: VOTER }
I20260812 06:18:34.841614 15037 raft_consensus.cc:385] T 00000000000000000000000000000000 P d90713e87fef46fca00e0ee426635d23 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:34.841656 15037 raft_consensus.cc:740] T 00000000000000000000000000000000 P d90713e87fef46fca00e0ee426635d23 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: d90713e87fef46fca00e0ee426635d23, State: Initialized, Role: FOLLOWER
I20260812 06:18:34.842301 15037 consensus_queue.cc:260] T 00000000000000000000000000000000 P d90713e87fef46fca00e0ee426635d23 [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: "d90713e87fef46fca00e0ee426635d23" member_type: VOTER }
I20260812 06:18:34.842446 15037 raft_consensus.cc:399] T 00000000000000000000000000000000 P d90713e87fef46fca00e0ee426635d23 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:34.842576 15037 raft_consensus.cc:493] T 00000000000000000000000000000000 P d90713e87fef46fca00e0ee426635d23 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:34.842751 15037 raft_consensus.cc:3060] T 00000000000000000000000000000000 P d90713e87fef46fca00e0ee426635d23 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:34.843602 15037 raft_consensus.cc:515] T 00000000000000000000000000000000 P d90713e87fef46fca00e0ee426635d23 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d90713e87fef46fca00e0ee426635d23" member_type: VOTER }
I20260812 06:18:34.844098 15037 leader_election.cc:304] T 00000000000000000000000000000000 P d90713e87fef46fca00e0ee426635d23 [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: d90713e87fef46fca00e0ee426635d23; no voters: 
I20260812 06:18:34.844450 15037 leader_election.cc:290] T 00000000000000000000000000000000 P d90713e87fef46fca00e0ee426635d23 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:34.844653 15042 raft_consensus.cc:2804] T 00000000000000000000000000000000 P d90713e87fef46fca00e0ee426635d23 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:34.844903 15042 raft_consensus.cc:697] T 00000000000000000000000000000000 P d90713e87fef46fca00e0ee426635d23 [term 1 LEADER]: Becoming Leader. State: Replica: d90713e87fef46fca00e0ee426635d23, State: Running, Role: LEADER
I20260812 06:18:34.845376 15042 consensus_queue.cc:237] T 00000000000000000000000000000000 P d90713e87fef46fca00e0ee426635d23 [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: "d90713e87fef46fca00e0ee426635d23" member_type: VOTER }
I20260812 06:18:34.845666 15037 sys_catalog.cc:565] T 00000000000000000000000000000000 P d90713e87fef46fca00e0ee426635d23 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:34.847648 15043 sys_catalog.cc:455] T 00000000000000000000000000000000 P d90713e87fef46fca00e0ee426635d23 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "d90713e87fef46fca00e0ee426635d23" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d90713e87fef46fca00e0ee426635d23" member_type: VOTER } }
I20260812 06:18:34.847777 15043 sys_catalog.cc:458] T 00000000000000000000000000000000 P d90713e87fef46fca00e0ee426635d23 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:34.848047 15044 sys_catalog.cc:455] T 00000000000000000000000000000000 P d90713e87fef46fca00e0ee426635d23 [sys.catalog]: SysCatalogTable state changed. Reason: New leader d90713e87fef46fca00e0ee426635d23. Latest consensus state: current_term: 1 leader_uuid: "d90713e87fef46fca00e0ee426635d23" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d90713e87fef46fca00e0ee426635d23" member_type: VOTER } }
I20260812 06:18:34.848119 15044 sys_catalog.cc:458] T 00000000000000000000000000000000 P d90713e87fef46fca00e0ee426635d23 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:34.848120 15064 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:34.848166 14921 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:34.850472 15064 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:34.855459 15064 catalog_manager.cc:1383] Generated new cluster ID: e7e622af8f0e455aae4971fe143eb13f
I20260812 06:18:34.855540 15064 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:34.868798 15064 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:34.870069 15064 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:34.880105 15064 catalog_manager.cc:6092] T 00000000000000000000000000000000 P d90713e87fef46fca00e0ee426635d23: Generated new TSK 0
I20260812 06:18:34.880962 15064 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:34.913271 14921 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:34.916482 15073 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:34.916577 15074 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:18:34.916764 14921 server_base.cc:1061] running on GCE node
W20260812 06:18:34.916580 15079 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:34.917121 14921 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:34.917181 14921 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:34.917204 14921 hybrid_clock.cc:648] HybridClock initialized: now 1786515514917204 us; error 0 us; skew 500 ppm
I20260812 06:18:34.918296 14921 webserver.cc:533] Webserver started at http://127.14.146.65:46673/ using document root <none> and password file <none>
I20260812 06:18:34.918486 14921 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:34.918545 14921 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:34.918641 14921 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:34.919112 14921 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514750243-14921-0/minicluster-data/ts-0-root/instance:
uuid: "3c2ce6a6b50449d4987d1bea4f65675f"
format_stamp: "Formatted at 2026-08-12 06:18:34 on dist-test-slave-twwt"
I20260812 06:18:34.921051 14921 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:34.922259 15092 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:34.922642 14921 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:34.922739 14921 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514750243-14921-0/minicluster-data/ts-0-root
uuid: "3c2ce6a6b50449d4987d1bea4f65675f"
format_stamp: "Formatted at 2026-08-12 06:18:34 on dist-test-slave-twwt"
I20260812 06:18:34.922827 14921 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514750243-14921-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514750243-14921-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514750243-14921-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:34.941252 14921 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:34.941797 14921 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:34.942377 14921 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:34.943354 14921 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:34.943405 14921 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:34.943450 14921 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:34.943506 14921 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:34.950332 14921 rpc_server.cc:307] RPC server started. Bound to: 127.14.146.65:45333
I20260812 06:18:34.950395 15191 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.14.146.65:45333 every 8 connection(s)
I20260812 06:18:34.960579 15192 heartbeater.cc:344] Connected to a master server at 127.14.146.126:32773
I20260812 06:18:34.960862 15192 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:34.961365 15192 heartbeater.cc:507] Master 127.14.146.126:32773 requested a full tablet report, sending...
I20260812 06:18:34.962931 14985 ts_manager.cc:194] Registered new tserver with Master: 3c2ce6a6b50449d4987d1bea4f65675f (127.14.146.65:45333)
I20260812 06:18:34.963434 14921 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012382543s
I20260812 06:18:34.964372 14985 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:41666
I20260812 06:18:34.973459 14985 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:41676:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:18:34.989077 15137 tablet_service.cc:1511] Processing CreateTablet for tablet ad5065dfff81403089b316b627336515 (DEFAULT_TABLE table=heavy-update-compaction-test [id=09d2a88ecb304815bfb42c7e2b5ccfe1]), partition=
I20260812 06:18:34.989634 15137 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet ad5065dfff81403089b316b627336515. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:34.992156 15219 tablet_bootstrap.cc:492] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f: Bootstrap starting.
I20260812 06:18:34.993371 15219 tablet_bootstrap.cc:654] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:34.995082 15219 tablet_bootstrap.cc:492] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f: No bootstrap required, opened a new log
I20260812 06:18:34.995172 15219 ts_tablet_manager.cc:1403] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:18:34.995702 15219 raft_consensus.cc:359] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3c2ce6a6b50449d4987d1bea4f65675f" member_type: VOTER last_known_addr { host: "127.14.146.65" port: 45333 } }
I20260812 06:18:34.995806 15219 raft_consensus.cc:385] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:34.995831 15219 raft_consensus.cc:740] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 3c2ce6a6b50449d4987d1bea4f65675f, State: Initialized, Role: FOLLOWER
I20260812 06:18:34.995990 15219 consensus_queue.cc:260] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f [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: "3c2ce6a6b50449d4987d1bea4f65675f" member_type: VOTER last_known_addr { host: "127.14.146.65" port: 45333 } }
I20260812 06:18:34.996064 15219 raft_consensus.cc:399] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:34.996114 15219 raft_consensus.cc:493] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:34.996170 15219 raft_consensus.cc:3060] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:34.997004 15219 raft_consensus.cc:515] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3c2ce6a6b50449d4987d1bea4f65675f" member_type: VOTER last_known_addr { host: "127.14.146.65" port: 45333 } }
I20260812 06:18:34.997177 15219 leader_election.cc:304] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f [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: 3c2ce6a6b50449d4987d1bea4f65675f; no voters: 
I20260812 06:18:34.997442 15219 leader_election.cc:290] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:34.997547 15223 raft_consensus.cc:2804] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:34.997769 15223 raft_consensus.cc:697] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f [term 1 LEADER]: Becoming Leader. State: Replica: 3c2ce6a6b50449d4987d1bea4f65675f, State: Running, Role: LEADER
I20260812 06:18:34.997900 15219 ts_tablet_manager.cc:1434] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:18:34.997968 15223 consensus_queue.cc:237] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f [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: "3c2ce6a6b50449d4987d1bea4f65675f" member_type: VOTER last_known_addr { host: "127.14.146.65" port: 45333 } }
I20260812 06:18:34.998204 15192 heartbeater.cc:499] Master 127.14.146.126:32773 was elected leader, sending a full tablet report...
I20260812 06:18:35.001267 14985 catalog_manager.cc:5719] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f reported cstate change: term changed from 0 to 1, leader changed from <none> to 3c2ce6a6b50449d4987d1bea4f65675f (127.14.146.65). New cstate: current_term: 1 leader_uuid: "3c2ce6a6b50449d4987d1bea4f65675f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3c2ce6a6b50449d4987d1bea4f65675f" member_type: VOTER last_known_addr { host: "127.14.146.65" port: 45333 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:35.067476 14921 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.057s	user 0.015s	sys 0.010s
I20260812 06:18:35.201642 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling FlushMRSOp(ad5065dfff81403089b316b627336515): perf score=15.086190
I20260812 06:18:35.359655 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: FlushMRSOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.158s	user 0.109s	sys 0.039s Metrics: {"bytes_written":11897249,"cfile_init":1,"compiler_manager_pool.queue_time_us":216,"delete_count":0,"dirs.queue_time_us":75,"dirs.run_cpu_time_us":231,"dirs.run_wall_time_us":929,"drs_written":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4,"lbm_write_time_us":38419,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":134,"threads_started":1,"update_count":1450}
I20260812 06:18:35.361016 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling LogGCOp(ad5065dfff81403089b316b627336515): free 20743880 bytes of WAL
I20260812 06:18:35.361387 15097 log_reader.cc:385] T ad5065dfff81403089b316b627336515: removed 2 log segments from log reader
I20260812 06:18:35.361467 15097 log.cc:1079] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/ad5065dfff81403089b316b627336515/wal-000000001 (ops 1-6)
I20260812 06:18:35.361528 15097 log.cc:1079] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/ad5065dfff81403089b316b627336515/wal-000000002 (ops 7-11)
I20260812 06:18:35.367609 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: LogGCOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.006s	user 0.000s	sys 0.005s Metrics: {}
I20260812 06:18:35.368088 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515): perf score=2.188937
I20260812 06:18:35.386795 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.018s	user 0.017s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6925,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:35.387423 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling UndoDeltaBlockGCOp(ad5065dfff81403089b316b627336515): 12719216 bytes on disk
I20260812 06:18:35.388283 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: UndoDeltaBlockGCOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":94,"lbm_reads_lt_1ms":4}
I20260812 06:18:35.388895 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling MajorDeltaCompactionOp(ad5065dfff81403089b316b627336515): perf score=1.000000
I20260812 06:18:35.526081 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: MajorDeltaCompactionOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.137s	user 0.097s	sys 0.040s Metrics: {"cfile_cache_miss":422,"cfile_cache_miss_bytes":20262036,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":593,"lbm_read_time_us":10228,"lbm_reads_lt_1ms":454,"lbm_write_time_us":24710,"lbm_writes_lt_1ms":433,"mutex_wait_us":26,"peak_mem_usage":49238594,"reinsert_count":0,"spinlock_wait_cycles":18176,"thread_start_us":312,"threads_started":5,"update_count":1950}
I20260812 06:18:35.526717 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515): perf score=10.126437
I20260812 06:18:35.571650 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.045s	user 0.029s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18761,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:35.572120 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515): perf score=2.188937
I20260812 06:18:35.584113 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.012s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4244,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:35.584721 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling MajorDeltaCompactionOp(ad5065dfff81403089b316b627336515): perf score=1.000000
I20260812 06:18:35.730540 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: MajorDeltaCompactionOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.146s	user 0.116s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":204,"lbm_read_time_us":9437,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28792,"lbm_writes_lt_1ms":443,"mutex_wait_us":70,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10368,"update_count":2000}
I20260812 06:18:35.731534 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515): perf score=10.126437
I20260812 06:18:35.777999 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.046s	user 0.029s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20304,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:35.778661 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515): perf score=2.188937
I20260812 06:18:35.793504 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.015s	user 0.003s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5462,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:35.794049 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling MajorDeltaCompactionOp(ad5065dfff81403089b316b627336515): perf score=1.000000
I20260812 06:18:35.933249 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: MajorDeltaCompactionOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.139s	user 0.104s	sys 0.034s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":655,"lbm_read_time_us":10312,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27897,"lbm_writes_lt_1ms":443,"mutex_wait_us":373,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2000}
I20260812 06:18:35.934038 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515): perf score=10.126437
I20260812 06:18:35.990445 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.056s	user 0.016s	sys 0.036s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":20464,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:35.991119 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515): perf score=2.188937
I20260812 06:18:36.007802 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.017s	user 0.003s	sys 0.013s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6319,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:36.008422 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling MajorDeltaCompactionOp(ad5065dfff81403089b316b627336515): perf score=1.000000
I20260812 06:18:36.171720 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: MajorDeltaCompactionOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.163s	user 0.115s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1140,"lbm_read_time_us":12308,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26724,"lbm_writes_lt_1ms":443,"mutex_wait_us":358,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:18:36.172247 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515): perf score=10.126437
I20260812 06:18:36.224772 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.052s	user 0.021s	sys 0.017s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17998,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:36.225308 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515): perf score=2.188937
I20260812 06:18:36.236706 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4355,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:36.237290 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling MajorDeltaCompactionOp(ad5065dfff81403089b316b627336515): perf score=1.000000
I20260812 06:18:36.362646 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: MajorDeltaCompactionOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.125s	user 0.099s	sys 0.025s 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":1017,"lbm_read_time_us":10263,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23888,"lbm_writes_lt_1ms":443,"mutex_wait_us":1,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2000}
I20260812 06:18:36.363422 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515): perf score=10.126437
I20260812 06:18:36.401086 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.037s	user 0.016s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16015,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:36.401678 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515): perf score=2.188937
I20260812 06:18:36.419116 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.017s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5481,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:36.419730 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling MajorDeltaCompactionOp(ad5065dfff81403089b316b627336515): perf score=1.000000
I20260812 06:18:36.547236 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: MajorDeltaCompactionOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.127s	user 0.093s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":459,"lbm_read_time_us":8427,"lbm_reads_lt_1ms":468,"lbm_write_time_us":26429,"lbm_writes_lt_1ms":443,"mutex_wait_us":110,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:18:36.548022 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515): perf score=11.118625
I20260812 06:18:36.595520 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.047s	user 0.011s	sys 0.036s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":17988,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:36.596131 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515): perf score=2.188937
I20260812 06:18:36.616536 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.020s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102660,"delete_count":0,"lbm_write_time_us":6802,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:36.617048 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515): perf score=2.188937
I20260812 06:18:36.627277 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3837,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:36.627820 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling FlushMRSOp(ad5065dfff81403089b316b627336515): perf score=1.000000
I20260812 06:18:36.663538 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: FlushMRSOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.036s	user 0.033s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":76,"dirs.run_cpu_time_us":276,"dirs.run_wall_time_us":1428,"drs_written":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2065,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:36.664484 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling LogGCOp(ad5065dfff81403089b316b627336515): free 112239314 bytes of WAL
I20260812 06:18:36.664716 15097 log_reader.cc:385] T ad5065dfff81403089b316b627336515: removed 11 log segments from log reader
I20260812 06:18:36.664758 15097 log.cc:1079] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/ad5065dfff81403089b316b627336515/wal-000000003 (ops 12-16)
I20260812 06:18:36.664816 15097 log.cc:1079] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/ad5065dfff81403089b316b627336515/wal-000000004 (ops 17-21)
I20260812 06:18:36.664860 15097 log.cc:1079] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/ad5065dfff81403089b316b627336515/wal-000000005 (ops 22-26)
I20260812 06:18:36.664901 15097 log.cc:1079] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/ad5065dfff81403089b316b627336515/wal-000000006 (ops 27-31)
I20260812 06:18:36.664945 15097 log.cc:1079] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/ad5065dfff81403089b316b627336515/wal-000000007 (ops 32-36)
I20260812 06:18:36.664987 15097 log.cc:1079] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/ad5065dfff81403089b316b627336515/wal-000000008 (ops 37-41)
I20260812 06:18:36.665026 15097 log.cc:1079] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/ad5065dfff81403089b316b627336515/wal-000000009 (ops 42-46)
I20260812 06:18:36.665066 15097 log.cc:1079] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/ad5065dfff81403089b316b627336515/wal-000000010 (ops 47-50)
I20260812 06:18:36.665105 15097 log.cc:1079] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/ad5065dfff81403089b316b627336515/wal-000000011 (ops 51-55)
I20260812 06:18:36.665143 15097 log.cc:1079] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/ad5065dfff81403089b316b627336515/wal-000000012 (ops 56-60)
I20260812 06:18:36.665182 15097 log.cc:1079] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/ad5065dfff81403089b316b627336515/wal-000000013 (ops 61-65)
I20260812 06:18:36.689699 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: LogGCOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.025s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:18:36.690196 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515): perf score=2.188937
I20260812 06:18:36.711342 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.021s	user 0.009s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6489,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:36.711802 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515): perf score=2.188937
I20260812 06:18:36.722769 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.011s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4079,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:36.723402 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling UndoDeltaBlockGCOp(ad5065dfff81403089b316b627336515): 448 bytes on disk
I20260812 06:18:36.724267 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: UndoDeltaBlockGCOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":117,"lbm_reads_lt_1ms":4}
I20260812 06:18:36.724944 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling MajorDeltaCompactionOp(ad5065dfff81403089b316b627336515): perf score=1.000000
I20260812 06:18:36.926977 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: MajorDeltaCompactionOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.202s	user 0.124s	sys 0.076s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979861,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":861,"lbm_read_time_us":15716,"lbm_reads_lt_1ms":775,"lbm_write_time_us":39460,"lbm_writes_lt_1ms":743,"mutex_wait_us":366,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":23936,"thread_start_us":107,"threads_started":1,"update_count":3500}
I20260812 06:18:36.928588 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515): perf score=14.095187
I20260812 06:18:36.977674 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.049s	user 0.034s	sys 0.012s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":21501,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:36.978327 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515): perf score=2.188937
I20260812 06:18:36.998963 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.020s	user 0.012s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6486,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":500}
I20260812 06:18:36.999426 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling MajorDeltaCompactionOp(ad5065dfff81403089b316b627336515): perf score=1.000000
I20260812 06:18:37.163959 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: MajorDeltaCompactionOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.164s	user 0.117s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774685,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":2068,"lbm_read_time_us":10157,"lbm_reads_lt_1ms":564,"lbm_write_time_us":33827,"lbm_writes_lt_1ms":543,"mutex_wait_us":1597,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:37.164538 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515): perf score=14.095187
I20260812 06:18:37.226019 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.061s	user 0.021s	sys 0.023s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21429,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:37.226583 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515): perf score=2.188937
I20260812 06:18:37.238569 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4105,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:37.239238 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling MajorDeltaCompactionOp(ad5065dfff81403089b316b627336515): perf score=1.000000
I20260812 06:18:37.430697 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: MajorDeltaCompactionOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.191s	user 0.128s	sys 0.063s 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":275,"lbm_read_time_us":13684,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33216,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":19840,"update_count":2500}
I20260812 06:18:37.431403 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515): perf score=14.095187
I20260812 06:18:37.480798 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.049s	user 0.028s	sys 0.013s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19918,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:37.481297 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling MajorDeltaCompactionOp(ad5065dfff81403089b316b627336515): perf score=1.000000
I20260812 06:18:37.643415 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: MajorDeltaCompactionOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.162s	user 0.117s	sys 0.039s 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":890,"lbm_read_time_us":11358,"lbm_reads_lt_1ms":463,"lbm_write_time_us":26066,"lbm_writes_lt_1ms":443,"mutex_wait_us":310,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:18:37.644119 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515): perf score=14.095187
I20260812 06:18:37.693713 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.049s	user 0.030s	sys 0.012s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":20399,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:37.694281 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515): perf score=2.188937
I20260812 06:18:37.706645 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4141,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:37.707342 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling MajorDeltaCompactionOp(ad5065dfff81403089b316b627336515): perf score=1.000000
I20260812 06:18:37.906757 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: MajorDeltaCompactionOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.199s	user 0.113s	sys 0.075s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774692,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":462,"lbm_read_time_us":12667,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32693,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2500}
I20260812 06:18:37.908407 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515): perf score=14.095187
I20260812 06:18:37.967875 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.059s	user 0.025s	sys 0.032s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25245,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:37.968674 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515): perf score=2.188937
I20260812 06:18:37.994472 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.026s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5362,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:37.995059 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515): perf score=2.188937
I20260812 06:18:38.005785 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.011s	user 0.003s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4147,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:38.006350 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling MajorDeltaCompactionOp(ad5065dfff81403089b316b627336515): perf score=1.000000
I20260812 06:18:38.216254 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: MajorDeltaCompactionOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.210s	user 0.123s	sys 0.080s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877218,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1025,"lbm_read_time_us":14903,"lbm_reads_lt_1ms":673,"lbm_write_time_us":32687,"lbm_writes_lt_1ms":643,"mutex_wait_us":60,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":13440,"update_count":3000}
I20260812 06:18:38.216912 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515): perf score=14.095187
I20260812 06:18:38.274029 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.057s	user 0.041s	sys 0.011s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24304,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:38.274694 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515): perf score=2.188937
I20260812 06:18:38.301486 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.027s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5221,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:38.302093 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling FlushMRSOp(ad5065dfff81403089b316b627336515): perf score=1.000000
I20260812 06:18:38.348083 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: FlushMRSOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.046s	user 0.025s	sys 0.007s Metrics: {"bytes_written":1357580,"cfile_init":1,"dirs.queue_time_us":84,"dirs.run_cpu_time_us":196,"dirs.run_wall_time_us":1260,"drs_written":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2901,"lbm_writes_lt_1ms":44,"peak_mem_usage":0,"rows_written":33}
I20260812 06:18:38.348904 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515): perf score=3.181125
I20260812 06:18:38.364531 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.015s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4430855,"delete_count":0,"lbm_write_time_us":4562,"lbm_writes_lt_1ms":111,"reinsert_count":0,"update_count":540}
I20260812 06:18:38.365111 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling LogGCOp(ad5065dfff81403089b316b627336515): free 140885396 bytes of WAL
I20260812 06:18:38.365335 15097 log_reader.cc:385] T ad5065dfff81403089b316b627336515: removed 14 log segments from log reader
I20260812 06:18:38.365392 15097 log.cc:1079] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/ad5065dfff81403089b316b627336515/wal-000000014 (ops 66-70)
I20260812 06:18:38.365453 15097 log.cc:1079] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/ad5065dfff81403089b316b627336515/wal-000000015 (ops 71-75)
I20260812 06:18:38.365489 15097 log.cc:1079] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/ad5065dfff81403089b316b627336515/wal-000000016 (ops 76-80)
I20260812 06:18:38.365525 15097 log.cc:1079] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/ad5065dfff81403089b316b627336515/wal-000000017 (ops 81-85)
I20260812 06:18:38.365562 15097 log.cc:1079] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/ad5065dfff81403089b316b627336515/wal-000000018 (ops 86-90)
I20260812 06:18:38.365597 15097 log.cc:1079] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/ad5065dfff81403089b316b627336515/wal-000000019 (ops 91-94)
I20260812 06:18:38.365633 15097 log.cc:1079] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/ad5065dfff81403089b316b627336515/wal-000000020 (ops 95-99)
I20260812 06:18:38.365669 15097 log.cc:1079] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/ad5065dfff81403089b316b627336515/wal-000000021 (ops 100-104)
I20260812 06:18:38.365706 15097 log.cc:1079] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/ad5065dfff81403089b316b627336515/wal-000000022 (ops 105-109)
I20260812 06:18:38.365742 15097 log.cc:1079] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/ad5065dfff81403089b316b627336515/wal-000000023 (ops 110-114)
I20260812 06:18:38.365777 15097 log.cc:1079] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/ad5065dfff81403089b316b627336515/wal-000000024 (ops 115-118)
I20260812 06:18:38.365814 15097 log.cc:1079] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/ad5065dfff81403089b316b627336515/wal-000000025 (ops 119-123)
I20260812 06:18:38.365849 15097 log.cc:1079] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/ad5065dfff81403089b316b627336515/wal-000000026 (ops 124-128)
I20260812 06:18:38.365885 15097 log.cc:1079] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/ad5065dfff81403089b316b627336515/wal-000000027 (ops 129-132)
I20260812 06:18:38.399274 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: LogGCOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.034s	user 0.000s	sys 0.033s Metrics: {}
I20260812 06:18:38.399782 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515): perf score=2.188937
I20260812 06:18:38.418102 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.018s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4184711,"delete_count":0,"lbm_write_time_us":7171,"lbm_writes_lt_1ms":105,"reinsert_count":0,"update_count":510}
I20260812 06:18:38.418659 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling UndoDeltaBlockGCOp(ad5065dfff81403089b316b627336515): 507 bytes on disk
I20260812 06:18:38.419121 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: UndoDeltaBlockGCOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4}
I20260812 06:18:38.419668 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515): perf score=2.188937
I20260812 06:18:38.430490 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.011s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4200,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:38.431233 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling MajorDeltaCompactionOp(ad5065dfff81403089b316b627336515): perf score=1.000000
I20260812 06:18:38.674645 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: MajorDeltaCompactionOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.243s	user 0.150s	sys 0.092s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37082276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":425,"lbm_read_time_us":18445,"lbm_reads_lt_1ms":875,"lbm_write_time_us":44920,"lbm_writes_lt_1ms":843,"mutex_wait_us":42,"peak_mem_usage":100395616,"reinsert_count":0,"thread_start_us":83,"threads_started":1,"update_count":4000}
I20260812 06:18:38.675316 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515): perf score=18.063937
I20260812 06:18:38.742548 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.067s	user 0.035s	sys 0.027s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":32364,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:18:38.743099 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515): perf score=3.181125
I20260812 06:18:38.759776 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.016s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":5039,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:38.760269 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515): perf score=2.188937
I20260812 06:18:38.770570 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3838,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:38.771109 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling MajorDeltaCompactionOp(ad5065dfff81403089b316b627336515): perf score=1.000000
I20260812 06:18:38.970372 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: MajorDeltaCompactionOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.199s	user 0.158s	sys 0.040s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32979623,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":244,"lbm_read_time_us":15294,"lbm_reads_lt_1ms":773,"lbm_write_time_us":42038,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":3500}
I20260812 06:18:38.971092 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515): perf score=14.095187
I20260812 06:18:39.024061 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.053s	user 0.024s	sys 0.027s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24127,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:39.024624 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515): perf score=2.188937
I20260812 06:18:39.045841 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.021s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5820,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:39.046569 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling MajorDeltaCompactionOp(ad5065dfff81403089b316b627336515): perf score=1.000000
I20260812 06:18:39.218101 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: MajorDeltaCompactionOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.171s	user 0.121s	sys 0.049s 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":1447,"lbm_read_time_us":11166,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31996,"lbm_writes_lt_1ms":543,"mutex_wait_us":376,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7552,"update_count":2500}
I20260812 06:18:39.218889 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515): perf score=14.095187
I20260812 06:18:39.279767 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.061s	user 0.035s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25215,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:39.280385 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling MajorDeltaCompactionOp(ad5065dfff81403089b316b627336515): perf score=1.000000
I20260812 06:18:39.443423 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: MajorDeltaCompactionOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.163s	user 0.116s	sys 0.037s 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":609,"lbm_read_time_us":10648,"lbm_reads_lt_1ms":463,"lbm_write_time_us":27034,"lbm_writes_lt_1ms":443,"mutex_wait_us":69,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2000}
I20260812 06:18:39.444187 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515): perf score=14.095187
I20260812 06:18:39.503173 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.059s	user 0.037s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":27886,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:39.503962 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515): perf score=2.188937
I20260812 06:18:39.523312 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.019s	user 0.014s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":7555,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:39.523898 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling MajorDeltaCompactionOp(ad5065dfff81403089b316b627336515): perf score=1.000000
I20260812 06:18:39.719743 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: MajorDeltaCompactionOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.196s	user 0.130s	sys 0.060s 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":163,"lbm_read_time_us":14676,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32679,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":17152,"update_count":2500}
I20260812 06:18:39.720643 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515): perf score=14.095187
I20260812 06:18:39.773977 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.053s	user 0.008s	sys 0.031s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20010,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:39.774505 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515): perf score=2.188937
I20260812 06:18:39.787515 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.013s	user 0.003s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4640,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:39.788218 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling FlushMRSOp(ad5065dfff81403089b316b627336515): perf score=1.000000
I20260812 06:18:39.817010 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: FlushMRSOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.029s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1152512,"cfile_init":1,"dirs.queue_time_us":66,"dirs.run_cpu_time_us":169,"dirs.run_wall_time_us":1180,"drs_written":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1783,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:39.817817 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling LogGCOp(ad5065dfff81403089b316b627336515): free 112692616 bytes of WAL
I20260812 06:18:39.818104 15097 log_reader.cc:385] T ad5065dfff81403089b316b627336515: removed 11 log segments from log reader
I20260812 06:18:39.818166 15097 log.cc:1079] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/ad5065dfff81403089b316b627336515/wal-000000028 (ops 133-137)
I20260812 06:18:39.818207 15097 log.cc:1079] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/ad5065dfff81403089b316b627336515/wal-000000029 (ops 138-142)
I20260812 06:18:39.818233 15097 log.cc:1079] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/ad5065dfff81403089b316b627336515/wal-000000030 (ops 143-147)
I20260812 06:18:39.818256 15097 log.cc:1079] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/ad5065dfff81403089b316b627336515/wal-000000031 (ops 148-152)
I20260812 06:18:39.818284 15097 log.cc:1079] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/ad5065dfff81403089b316b627336515/wal-000000032 (ops 153-157)
I20260812 06:18:39.818306 15097 log.cc:1079] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/ad5065dfff81403089b316b627336515/wal-000000033 (ops 158-162)
I20260812 06:18:39.818337 15097 log.cc:1079] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/ad5065dfff81403089b316b627336515/wal-000000034 (ops 163-167)
I20260812 06:18:39.818362 15097 log.cc:1079] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/ad5065dfff81403089b316b627336515/wal-000000035 (ops 168-172)
I20260812 06:18:39.818395 15097 log.cc:1079] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/ad5065dfff81403089b316b627336515/wal-000000036 (ops 173-177)
I20260812 06:18:39.818432 15097 log.cc:1079] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/ad5065dfff81403089b316b627336515/wal-000000037 (ops 178-182)
I20260812 06:18:39.818461 15097 log.cc:1079] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/ad5065dfff81403089b316b627336515/wal-000000038 (ops 183-187)
I20260812 06:18:39.850667 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: LogGCOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.033s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:18:39.851106 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515): perf score=2.188937
I20260812 06:18:39.880669 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.029s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5243,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:39.881297 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515): perf score=2.188937
I20260812 06:18:39.892859 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.011s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4501,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:39.893376 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling MajorDeltaCompactionOp(ad5065dfff81403089b316b627336515): perf score=1.000000
I20260812 06:18:40.138466 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: MajorDeltaCompactionOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.245s	user 0.159s	sys 0.083s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979749,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1388,"lbm_read_time_us":16515,"lbm_reads_lt_1ms":774,"lbm_write_time_us":43320,"lbm_writes_lt_1ms":743,"mutex_wait_us":374,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":4096,"thread_start_us":104,"threads_started":1,"update_count":3500}
I20260812 06:18:40.139264 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling UndoDeltaBlockGCOp(ad5065dfff81403089b316b627336515): 448 bytes on disk
I20260812 06:18:40.139822 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: UndoDeltaBlockGCOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":101,"lbm_reads_lt_1ms":4}
I20260812 06:18:40.140810 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515): perf score=17.071750
I20260812 06:18:40.148022 14921 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.080s	user 1.849s	sys 0.135s
I20260812 06:18:40.189615 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.049s	user 0.025s	sys 0.020s Metrics: {"bytes_written":19322619,"delete_count":0,"lbm_write_time_us":22513,"lbm_writes_lt_1ms":474,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2355}
I20260812 06:18:40.190361 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515): perf score=1.000000
I20260812 06:18:40.195727 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: FlushDeltaMemStoresOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.005s	user 0.004s	sys 0.000s Metrics: {"bytes_written":1189877,"delete_count":0,"lbm_write_time_us":1385,"lbm_writes_lt_1ms":32,"reinsert_count":0,"update_count":145}
I20260812 06:18:40.196175 15193 maintenance_manager.cc:419] P 3c2ce6a6b50449d4987d1bea4f65675f: Scheduling MajorDeltaCompactionOp(ad5065dfff81403089b316b627336515): perf score=1.000000
I20260812 06:18:40.196732 14921 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.048s	user 0.005s	sys 0.000s
I20260812 06:18:40.197371 14921 tablet_server.cc:179] TabletServer@127.14.146.65:0 shutting down...
I20260812 06:18:40.337001 15097 maintenance_manager.cc:643] P 3c2ce6a6b50449d4987d1bea4f65675f: MajorDeltaCompactionOp(ad5065dfff81403089b316b627336515) complete. Timing: real 0.141s	user 0.101s	sys 0.039s Metrics: {"cfile_cache_hit":30,"cfile_cache_hit_bytes":4262390,"cfile_cache_miss":502,"cfile_cache_miss_bytes":20512235,"cfile_init":4,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":749,"lbm_read_time_us":8736,"lbm_reads_lt_1ms":518,"lbm_write_time_us":25180,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:40.337707 14921 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:40.338207 14921 tablet_replica.cc:333] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f: stopping tablet replica
I20260812 06:18:40.338490 14921 raft_consensus.cc:2243] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:40.338796 14921 raft_consensus.cc:2272] T ad5065dfff81403089b316b627336515 P 3c2ce6a6b50449d4987d1bea4f65675f [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:40.355690 14921 tablet_server.cc:196] TabletServer@127.14.146.65:0 shutdown complete.
I20260812 06:18:40.384398 14921 master.cc:562] Master@127.14.146.126:32773 shutting down...
I20260812 06:18:40.388511 14921 raft_consensus.cc:2243] T 00000000000000000000000000000000 P d90713e87fef46fca00e0ee426635d23 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:40.388696 14921 raft_consensus.cc:2272] T 00000000000000000000000000000000 P d90713e87fef46fca00e0ee426635d23 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:40.388751 14921 tablet_replica.cc:333] T 00000000000000000000000000000000 P d90713e87fef46fca00e0ee426635d23: stopping tablet replica
I20260812 06:18:40.401293 14921 master.cc:584] Master@127.14.146.126:32773 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5752 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:40.513301 14921 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.14.146.126:36337
I20260812 06:18:40.513697 14921 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:40.515820 15247 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:40.515946 15250 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:18:40.516042 14921 server_base.cc:1061] running on GCE node
W20260812 06:18:40.516131 15252 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:40.516362 14921 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:40.516431 14921 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:40.516458 14921 hybrid_clock.cc:648] HybridClock initialized: now 1786515520516457 us; error 0 us; skew 500 ppm
I20260812 06:18:40.517475 14921 webserver.cc:533] Webserver started at http://127.14.146.126:36455/ using document root <none> and password file <none>
I20260812 06:18:40.517683 14921 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:40.517802 14921 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:40.517922 14921 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:40.518356 14921 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514750243-14921-0/minicluster-data/master-0-root/instance:
uuid: "ef733d18e27f4d968aad8014af16ee8a"
format_stamp: "Formatted at 2026-08-12 06:18:40 on dist-test-slave-twwt"
I20260812 06:18:40.520056 14921 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:40.521095 15259 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:40.521358 14921 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:40.521463 14921 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514750243-14921-0/minicluster-data/master-0-root
uuid: "ef733d18e27f4d968aad8014af16ee8a"
format_stamp: "Formatted at 2026-08-12 06:18:40 on dist-test-slave-twwt"
I20260812 06:18:40.521565 14921 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514750243-14921-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514750243-14921-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514750243-14921-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:40.543565 14921 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:40.544034 14921 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:40.548511 14921 rpc_server.cc:307] RPC server started. Bound to: 127.14.146.126:36337
I20260812 06:18:40.556205 15362 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:40.556814 15361 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.14.146.126:36337 every 8 connection(s)
I20260812 06:18:40.567816 15362 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P ef733d18e27f4d968aad8014af16ee8a: Bootstrap starting.
I20260812 06:18:40.568713 15362 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P ef733d18e27f4d968aad8014af16ee8a: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:40.569875 15362 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P ef733d18e27f4d968aad8014af16ee8a: No bootstrap required, opened a new log
I20260812 06:18:40.570262 15362 raft_consensus.cc:359] T 00000000000000000000000000000000 P ef733d18e27f4d968aad8014af16ee8a [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ef733d18e27f4d968aad8014af16ee8a" member_type: VOTER }
I20260812 06:18:40.570351 15362 raft_consensus.cc:385] T 00000000000000000000000000000000 P ef733d18e27f4d968aad8014af16ee8a [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:40.570374 15362 raft_consensus.cc:740] T 00000000000000000000000000000000 P ef733d18e27f4d968aad8014af16ee8a [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: ef733d18e27f4d968aad8014af16ee8a, State: Initialized, Role: FOLLOWER
I20260812 06:18:40.570499 15362 consensus_queue.cc:260] T 00000000000000000000000000000000 P ef733d18e27f4d968aad8014af16ee8a [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: "ef733d18e27f4d968aad8014af16ee8a" member_type: VOTER }
I20260812 06:18:40.570559 15362 raft_consensus.cc:399] T 00000000000000000000000000000000 P ef733d18e27f4d968aad8014af16ee8a [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:40.570580 15362 raft_consensus.cc:493] T 00000000000000000000000000000000 P ef733d18e27f4d968aad8014af16ee8a [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:40.570683 15362 raft_consensus.cc:3060] T 00000000000000000000000000000000 P ef733d18e27f4d968aad8014af16ee8a [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:40.571425 15362 raft_consensus.cc:515] T 00000000000000000000000000000000 P ef733d18e27f4d968aad8014af16ee8a [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ef733d18e27f4d968aad8014af16ee8a" member_type: VOTER }
I20260812 06:18:40.571552 15362 leader_election.cc:304] T 00000000000000000000000000000000 P ef733d18e27f4d968aad8014af16ee8a [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: ef733d18e27f4d968aad8014af16ee8a; no voters: 
I20260812 06:18:40.571717 15362 leader_election.cc:290] T 00000000000000000000000000000000 P ef733d18e27f4d968aad8014af16ee8a [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:40.571878 15365 raft_consensus.cc:2804] T 00000000000000000000000000000000 P ef733d18e27f4d968aad8014af16ee8a [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:40.572088 15365 raft_consensus.cc:697] T 00000000000000000000000000000000 P ef733d18e27f4d968aad8014af16ee8a [term 1 LEADER]: Becoming Leader. State: Replica: ef733d18e27f4d968aad8014af16ee8a, State: Running, Role: LEADER
I20260812 06:18:40.572230 15362 sys_catalog.cc:565] T 00000000000000000000000000000000 P ef733d18e27f4d968aad8014af16ee8a [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:40.572258 15365 consensus_queue.cc:237] T 00000000000000000000000000000000 P ef733d18e27f4d968aad8014af16ee8a [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: "ef733d18e27f4d968aad8014af16ee8a" member_type: VOTER }
I20260812 06:18:40.572727 15367 sys_catalog.cc:455] T 00000000000000000000000000000000 P ef733d18e27f4d968aad8014af16ee8a [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "ef733d18e27f4d968aad8014af16ee8a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ef733d18e27f4d968aad8014af16ee8a" member_type: VOTER } }
I20260812 06:18:40.572837 15367 sys_catalog.cc:458] T 00000000000000000000000000000000 P ef733d18e27f4d968aad8014af16ee8a [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:40.572743 15368 sys_catalog.cc:455] T 00000000000000000000000000000000 P ef733d18e27f4d968aad8014af16ee8a [sys.catalog]: SysCatalogTable state changed. Reason: New leader ef733d18e27f4d968aad8014af16ee8a. Latest consensus state: current_term: 1 leader_uuid: "ef733d18e27f4d968aad8014af16ee8a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ef733d18e27f4d968aad8014af16ee8a" member_type: VOTER } }
I20260812 06:18:40.573086 15368 sys_catalog.cc:458] T 00000000000000000000000000000000 P ef733d18e27f4d968aad8014af16ee8a [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:40.573539 15371 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:40.574466 15371 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:40.574690 14921 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:40.576418 15371 catalog_manager.cc:1383] Generated new cluster ID: 698f847c622f439ca671fe7fae84b99e
I20260812 06:18:40.576478 15371 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:40.581753 15371 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:40.582397 15371 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:40.596778 15371 catalog_manager.cc:6092] T 00000000000000000000000000000000 P ef733d18e27f4d968aad8014af16ee8a: Generated new TSK 0
I20260812 06:18:40.597023 15371 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:40.607555 14921 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:40.609814 15397 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:40.609889 14921 server_base.cc:1061] running on GCE node
W20260812 06:18:40.609907 15400 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:40.609907 15402 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:40.610217 14921 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:40.610265 14921 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:40.610281 14921 hybrid_clock.cc:648] HybridClock initialized: now 1786515520610281 us; error 0 us; skew 500 ppm
I20260812 06:18:40.611215 14921 webserver.cc:533] Webserver started at http://127.14.146.65:46103/ using document root <none> and password file <none>
I20260812 06:18:40.611366 14921 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:40.611410 14921 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:40.611477 14921 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:40.611847 14921 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514750243-14921-0/minicluster-data/ts-0-root/instance:
uuid: "2943ecf5581a43f08dbc159290ec0646"
format_stamp: "Formatted at 2026-08-12 06:18:40 on dist-test-slave-twwt"
I20260812 06:18:40.613374 14921 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:40.614292 15410 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:40.614713 14921 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:40.614809 14921 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514750243-14921-0/minicluster-data/ts-0-root
uuid: "2943ecf5581a43f08dbc159290ec0646"
format_stamp: "Formatted at 2026-08-12 06:18:40 on dist-test-slave-twwt"
I20260812 06:18:40.614904 14921 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514750243-14921-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514750243-14921-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514750243-14921-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:40.624974 14921 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:40.625430 14921 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:40.625787 14921 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:40.626313 14921 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:40.626379 14921 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:40.626446 14921 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:40.626480 14921 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:40.630903 14921 rpc_server.cc:307] RPC server started. Bound to: 127.14.146.65:37475
I20260812 06:18:40.630935 15522 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.14.146.65:37475 every 8 connection(s)
I20260812 06:18:40.635831 15523 heartbeater.cc:344] Connected to a master server at 127.14.146.126:36337
I20260812 06:18:40.635979 15523 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:40.636214 15523 heartbeater.cc:507] Master 127.14.146.126:36337 requested a full tablet report, sending...
I20260812 06:18:40.636906 15294 ts_manager.cc:194] Registered new tserver with Master: 2943ecf5581a43f08dbc159290ec0646 (127.14.146.65:37475)
I20260812 06:18:40.636955 14921 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.005584873s
I20260812 06:18:40.637751 15294 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:59114
I20260812 06:18:40.644490 15294 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:59128:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:18:40.654187 15456 tablet_service.cc:1511] Processing CreateTablet for tablet 3c704536954a4a0b90c3a77f97b7db5e (DEFAULT_TABLE table=heavy-update-compaction-test [id=13b93cdf76664f5087d31cccfef59a02]), partition=
I20260812 06:18:40.654515 15456 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 3c704536954a4a0b90c3a77f97b7db5e. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:40.656805 15539 tablet_bootstrap.cc:492] T 3c704536954a4a0b90c3a77f97b7db5e P 2943ecf5581a43f08dbc159290ec0646: Bootstrap starting.
I20260812 06:18:40.657716 15539 tablet_bootstrap.cc:654] T 3c704536954a4a0b90c3a77f97b7db5e P 2943ecf5581a43f08dbc159290ec0646: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:40.658944 15539 tablet_bootstrap.cc:492] T 3c704536954a4a0b90c3a77f97b7db5e P 2943ecf5581a43f08dbc159290ec0646: No bootstrap required, opened a new log
I20260812 06:18:40.659061 15539 ts_tablet_manager.cc:1403] T 3c704536954a4a0b90c3a77f97b7db5e P 2943ecf5581a43f08dbc159290ec0646: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:40.659597 15539 raft_consensus.cc:359] T 3c704536954a4a0b90c3a77f97b7db5e P 2943ecf5581a43f08dbc159290ec0646 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2943ecf5581a43f08dbc159290ec0646" member_type: VOTER last_known_addr { host: "127.14.146.65" port: 37475 } }
I20260812 06:18:40.659739 15539 raft_consensus.cc:385] T 3c704536954a4a0b90c3a77f97b7db5e P 2943ecf5581a43f08dbc159290ec0646 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:40.659781 15539 raft_consensus.cc:740] T 3c704536954a4a0b90c3a77f97b7db5e P 2943ecf5581a43f08dbc159290ec0646 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 2943ecf5581a43f08dbc159290ec0646, State: Initialized, Role: FOLLOWER
I20260812 06:18:40.659958 15539 consensus_queue.cc:260] T 3c704536954a4a0b90c3a77f97b7db5e P 2943ecf5581a43f08dbc159290ec0646 [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: "2943ecf5581a43f08dbc159290ec0646" member_type: VOTER last_known_addr { host: "127.14.146.65" port: 37475 } }
I20260812 06:18:40.660049 15539 raft_consensus.cc:399] T 3c704536954a4a0b90c3a77f97b7db5e P 2943ecf5581a43f08dbc159290ec0646 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:40.660075 15539 raft_consensus.cc:493] T 3c704536954a4a0b90c3a77f97b7db5e P 2943ecf5581a43f08dbc159290ec0646 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:40.660111 15539 raft_consensus.cc:3060] T 3c704536954a4a0b90c3a77f97b7db5e P 2943ecf5581a43f08dbc159290ec0646 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:40.660843 15539 raft_consensus.cc:515] T 3c704536954a4a0b90c3a77f97b7db5e P 2943ecf5581a43f08dbc159290ec0646 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2943ecf5581a43f08dbc159290ec0646" member_type: VOTER last_known_addr { host: "127.14.146.65" port: 37475 } }
I20260812 06:18:40.660972 15539 leader_election.cc:304] T 3c704536954a4a0b90c3a77f97b7db5e P 2943ecf5581a43f08dbc159290ec0646 [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: 2943ecf5581a43f08dbc159290ec0646; no voters: 
I20260812 06:18:40.661145 15539 leader_election.cc:290] T 3c704536954a4a0b90c3a77f97b7db5e P 2943ecf5581a43f08dbc159290ec0646 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:40.661293 15543 raft_consensus.cc:2804] T 3c704536954a4a0b90c3a77f97b7db5e P 2943ecf5581a43f08dbc159290ec0646 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:40.661463 15539 ts_tablet_manager.cc:1434] T 3c704536954a4a0b90c3a77f97b7db5e P 2943ecf5581a43f08dbc159290ec0646: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:18:40.661502 15523 heartbeater.cc:499] Master 127.14.146.126:36337 was elected leader, sending a full tablet report...
I20260812 06:18:40.661537 15543 raft_consensus.cc:697] T 3c704536954a4a0b90c3a77f97b7db5e P 2943ecf5581a43f08dbc159290ec0646 [term 1 LEADER]: Becoming Leader. State: Replica: 2943ecf5581a43f08dbc159290ec0646, State: Running, Role: LEADER
I20260812 06:18:40.661657 15543 consensus_queue.cc:237] T 3c704536954a4a0b90c3a77f97b7db5e P 2943ecf5581a43f08dbc159290ec0646 [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: "2943ecf5581a43f08dbc159290ec0646" member_type: VOTER last_known_addr { host: "127.14.146.65" port: 37475 } }
I20260812 06:18:40.663105 15294 catalog_manager.cc:5719] T 3c704536954a4a0b90c3a77f97b7db5e P 2943ecf5581a43f08dbc159290ec0646 reported cstate change: term changed from 0 to 1, leader changed from <none> to 2943ecf5581a43f08dbc159290ec0646 (127.14.146.65). New cstate: current_term: 1 leader_uuid: "2943ecf5581a43f08dbc159290ec0646" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2943ecf5581a43f08dbc159290ec0646" member_type: VOTER last_known_addr { host: "127.14.146.65" port: 37475 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:40.725636 14921 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.056s	user 0.017s	sys 0.007s
I20260812 06:18:40.881942 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling FlushMRSOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=19.054940
I20260812 06:18:41.040537 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: FlushMRSOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.158s	user 0.116s	sys 0.040s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":87,"dirs.run_cpu_time_us":217,"dirs.run_wall_time_us":854,"drs_written":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4,"lbm_write_time_us":41334,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:18:41.041247 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling LogGCOp(3c704536954a4a0b90c3a77f97b7db5e): free 20290830 bytes of WAL
I20260812 06:18:41.041507 15416 log_reader.cc:385] T 3c704536954a4a0b90c3a77f97b7db5e: removed 2 log segments from log reader
I20260812 06:18:41.041558 15416 log.cc:1079] T 3c704536954a4a0b90c3a77f97b7db5e P 2943ecf5581a43f08dbc159290ec0646: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/3c704536954a4a0b90c3a77f97b7db5e/wal-000000001 (ops 1-6)
I20260812 06:18:41.041591 15416 log.cc:1079] T 3c704536954a4a0b90c3a77f97b7db5e P 2943ecf5581a43f08dbc159290ec0646: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/3c704536954a4a0b90c3a77f97b7db5e/wal-000000002 (ops 7-10)
I20260812 06:18:41.045992 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: LogGCOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.005s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:18:41.046383 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling UndoDeltaBlockGCOp(3c704536954a4a0b90c3a77f97b7db5e): 16411394 bytes on disk
I20260812 06:18:41.046942 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: UndoDeltaBlockGCOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4}
I20260812 06:18:41.047405 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=2.188937
I20260812 06:18:41.067633 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.020s	user 0.006s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6327,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:41.068164 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling MajorDeltaCompactionOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=1.000000
I20260812 06:18:41.220824 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: MajorDeltaCompactionOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.152s	user 0.099s	sys 0.045s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":558,"lbm_read_time_us":11811,"lbm_reads_lt_1ms":460,"lbm_write_time_us":25712,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":339,"threads_started":5,"update_count":2000}
I20260812 06:18:41.221508 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=14.095187
I20260812 06:18:41.279282 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.058s	user 0.038s	sys 0.015s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23560,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:41.279875 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=2.188937
I20260812 06:18:41.291891 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4251,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:41.292409 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling MajorDeltaCompactionOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=1.000000
I20260812 06:18:41.466917 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: MajorDeltaCompactionOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.174s	user 0.118s	sys 0.043s 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":350,"lbm_read_time_us":13300,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32690,"lbm_writes_lt_1ms":543,"mutex_wait_us":54,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":756736,"update_count":2500}
I20260812 06:18:41.467953 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=14.095187
I20260812 06:18:41.523916 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.055s	user 0.034s	sys 0.019s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":23990,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:41.524412 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=2.188937
I20260812 06:18:41.539417 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5531,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:41.540231 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling MajorDeltaCompactionOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=1.000000
I20260812 06:18:41.703933 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: MajorDeltaCompactionOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.163s	user 0.104s	sys 0.055s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":276,"lbm_read_time_us":10789,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30428,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":24448,"update_count":2500}
I20260812 06:18:41.704702 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=14.095187
I20260812 06:18:41.756784 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.052s	user 0.037s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22912,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:41.757391 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling MajorDeltaCompactionOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=1.000000
I20260812 06:18:41.909227 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: MajorDeltaCompactionOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.152s	user 0.092s	sys 0.060s 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":1273,"lbm_read_time_us":10535,"lbm_reads_lt_1ms":463,"lbm_write_time_us":24245,"lbm_writes_lt_1ms":443,"mutex_wait_us":354,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":20096,"update_count":2000}
I20260812 06:18:41.910061 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=14.095187
I20260812 06:18:41.965447 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.055s	user 0.040s	sys 0.013s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":25037,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:41.966243 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=2.188937
I20260812 06:18:41.992071 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.026s	user 0.015s	sys 0.006s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5777,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:41.992645 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling MajorDeltaCompactionOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=1.000000
I20260812 06:18:42.186945 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: MajorDeltaCompactionOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.194s	user 0.113s	sys 0.080s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1409,"lbm_read_time_us":13555,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30857,"lbm_writes_lt_1ms":543,"mutex_wait_us":669,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:42.187660 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=14.095187
I20260812 06:18:42.235002 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.047s	user 0.022s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20679,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:42.235737 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=2.188937
I20260812 06:18:42.251313 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5766,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:42.251797 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling FlushMRSOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=1.000000
I20260812 06:18:42.300873 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: FlushMRSOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.049s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":64,"dirs.run_cpu_time_us":225,"dirs.run_wall_time_us":1359,"drs_written":1,"lbm_read_time_us":100,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1936,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:18:42.301982 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling UndoDeltaBlockGCOp(3c704536954a4a0b90c3a77f97b7db5e): 462 bytes on disk
I20260812 06:18:42.302559 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: UndoDeltaBlockGCOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":78,"lbm_reads_lt_1ms":4}
I20260812 06:18:42.303068 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=3.181125
I20260812 06:18:42.316614 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.013s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4688,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:42.317137 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling LogGCOp(3c704536954a4a0b90c3a77f97b7db5e): free 112692309 bytes of WAL
I20260812 06:18:42.317375 15416 log_reader.cc:385] T 3c704536954a4a0b90c3a77f97b7db5e: removed 11 log segments from log reader
I20260812 06:18:42.317421 15416 log.cc:1079] T 3c704536954a4a0b90c3a77f97b7db5e P 2943ecf5581a43f08dbc159290ec0646: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/3c704536954a4a0b90c3a77f97b7db5e/wal-000000003 (ops 11-15)
I20260812 06:18:42.317472 15416 log.cc:1079] T 3c704536954a4a0b90c3a77f97b7db5e P 2943ecf5581a43f08dbc159290ec0646: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/3c704536954a4a0b90c3a77f97b7db5e/wal-000000004 (ops 16-20)
I20260812 06:18:42.317515 15416 log.cc:1079] T 3c704536954a4a0b90c3a77f97b7db5e P 2943ecf5581a43f08dbc159290ec0646: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/3c704536954a4a0b90c3a77f97b7db5e/wal-000000005 (ops 21-25)
I20260812 06:18:42.317574 15416 log.cc:1079] T 3c704536954a4a0b90c3a77f97b7db5e P 2943ecf5581a43f08dbc159290ec0646: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/3c704536954a4a0b90c3a77f97b7db5e/wal-000000006 (ops 26-30)
I20260812 06:18:42.317613 15416 log.cc:1079] T 3c704536954a4a0b90c3a77f97b7db5e P 2943ecf5581a43f08dbc159290ec0646: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/3c704536954a4a0b90c3a77f97b7db5e/wal-000000007 (ops 31-35)
I20260812 06:18:42.317667 15416 log.cc:1079] T 3c704536954a4a0b90c3a77f97b7db5e P 2943ecf5581a43f08dbc159290ec0646: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/3c704536954a4a0b90c3a77f97b7db5e/wal-000000008 (ops 36-40)
I20260812 06:18:42.317706 15416 log.cc:1079] T 3c704536954a4a0b90c3a77f97b7db5e P 2943ecf5581a43f08dbc159290ec0646: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/3c704536954a4a0b90c3a77f97b7db5e/wal-000000009 (ops 41-45)
I20260812 06:18:42.317750 15416 log.cc:1079] T 3c704536954a4a0b90c3a77f97b7db5e P 2943ecf5581a43f08dbc159290ec0646: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/3c704536954a4a0b90c3a77f97b7db5e/wal-000000010 (ops 46-50)
I20260812 06:18:42.317787 15416 log.cc:1079] T 3c704536954a4a0b90c3a77f97b7db5e P 2943ecf5581a43f08dbc159290ec0646: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/3c704536954a4a0b90c3a77f97b7db5e/wal-000000011 (ops 51-55)
I20260812 06:18:42.317826 15416 log.cc:1079] T 3c704536954a4a0b90c3a77f97b7db5e P 2943ecf5581a43f08dbc159290ec0646: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/3c704536954a4a0b90c3a77f97b7db5e/wal-000000012 (ops 56-60)
I20260812 06:18:42.317864 15416 log.cc:1079] T 3c704536954a4a0b90c3a77f97b7db5e P 2943ecf5581a43f08dbc159290ec0646: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/3c704536954a4a0b90c3a77f97b7db5e/wal-000000013 (ops 61-65)
I20260812 06:18:42.343228 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: LogGCOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.026s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:18:42.343628 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=2.188937
I20260812 06:18:42.365447 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.022s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5249,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:42.365964 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling LogGCOp(3c704536954a4a0b90c3a77f97b7db5e): free 12017983 bytes of WAL
I20260812 06:18:42.366181 15416 log_reader.cc:385] T 3c704536954a4a0b90c3a77f97b7db5e: removed 1 log segments from log reader
I20260812 06:18:42.366227 15416 log.cc:1079] T 3c704536954a4a0b90c3a77f97b7db5e P 2943ecf5581a43f08dbc159290ec0646: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/3c704536954a4a0b90c3a77f97b7db5e/wal-000000014 (ops 66-70)
I20260812 06:18:42.368826 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: LogGCOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:18:42.369176 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=2.188937
I20260812 06:18:42.380518 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.011s	user 0.004s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4037,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:42.381042 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling MajorDeltaCompactionOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=1.000000
I20260812 06:18:42.647043 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: MajorDeltaCompactionOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.266s	user 0.183s	sys 0.072s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37082271,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":3862,"dirs.run_cpu_time_us":538,"dirs.run_wall_time_us":3289,"lbm_read_time_us":20622,"lbm_reads_lt_1ms":875,"lbm_write_time_us":48701,"lbm_writes_lt_1ms":843,"mutex_wait_us":75,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":7680,"thread_start_us":112,"threads_started":1,"update_count":4000}
I20260812 06:18:42.647897 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=19.056125
I20260812 06:18:42.721154 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.073s	user 0.035s	sys 0.028s Metrics: {"bytes_written":21660989,"delete_count":0,"lbm_write_time_us":29851,"lbm_writes_lt_1ms":531,"mutex_wait_us":216,"reinsert_count":0,"update_count":2640}
I20260812 06:18:42.721710 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=5.165500
I20260812 06:18:42.748430 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.027s	user 0.016s	sys 0.004s Metrics: {"bytes_written":7056409,"delete_count":0,"lbm_write_time_us":8910,"lbm_writes_lt_1ms":175,"reinsert_count":0,"update_count":860}
I20260812 06:18:42.748961 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling MajorDeltaCompactionOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=1.000000
I20260812 06:18:42.964238 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: MajorDeltaCompactionOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.215s	user 0.133s	sys 0.074s Metrics: {"cfile_cache_miss":732,"cfile_cache_miss_bytes":32979520,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":233,"lbm_read_time_us":14522,"lbm_reads_lt_1ms":764,"lbm_write_time_us":44717,"lbm_writes_lt_1ms":743,"mutex_wait_us":60,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":13184,"update_count":3500}
I20260812 06:18:42.964862 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=18.063937
I20260812 06:18:43.025447 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.060s	user 0.018s	sys 0.037s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":26449,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:43.025974 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=2.188937
I20260812 06:18:43.037500 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4524,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:43.038156 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling MajorDeltaCompactionOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=1.000000
I20260812 06:18:43.209764 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: MajorDeltaCompactionOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.171s	user 0.135s	sys 0.036s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877104,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":355,"lbm_read_time_us":14269,"lbm_reads_lt_1ms":672,"lbm_write_time_us":35556,"lbm_writes_lt_1ms":643,"mutex_wait_us":49,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":3000}
I20260812 06:18:43.210464 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=14.095187
I20260812 06:18:43.258507 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.048s	user 0.028s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21244,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:43.259121 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=2.188937
I20260812 06:18:43.276152 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.017s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6695,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:43.276846 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling MajorDeltaCompactionOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=1.000000
I20260812 06:18:43.458209 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: MajorDeltaCompactionOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.181s	user 0.140s	sys 0.032s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":846,"lbm_read_time_us":12440,"lbm_reads_lt_1ms":564,"lbm_write_time_us":35463,"lbm_writes_lt_1ms":543,"mutex_wait_us":435,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":18688,"update_count":2500}
I20260812 06:18:43.459599 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=14.095187
I20260812 06:18:43.525719 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.066s	user 0.026s	sys 0.025s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":24357,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:43.526216 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=2.188937
I20260812 06:18:43.537366 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4221,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:43.538277 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling MajorDeltaCompactionOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=1.000000
I20260812 06:18:43.718374 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: MajorDeltaCompactionOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.180s	user 0.128s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":830,"lbm_read_time_us":13221,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30905,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7040,"update_count":2500}
I20260812 06:18:43.719152 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=14.095187
I20260812 06:18:43.783959 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.065s	user 0.037s	sys 0.027s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23979,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:43.784595 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=2.188937
I20260812 06:18:43.795832 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4398,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:43.796360 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling FlushMRSOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=1.000000
I20260812 06:18:43.843081 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: FlushMRSOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.047s	user 0.034s	sys 0.003s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":73,"dirs.run_cpu_time_us":187,"dirs.run_wall_time_us":1192,"drs_written":1,"lbm_read_time_us":79,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1968,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:18:43.843895 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling LogGCOp(3c704536954a4a0b90c3a77f97b7db5e): free 120553390 bytes of WAL
I20260812 06:18:43.844182 15416 log_reader.cc:385] T 3c704536954a4a0b90c3a77f97b7db5e: removed 12 log segments from log reader
I20260812 06:18:43.844233 15416 log.cc:1079] T 3c704536954a4a0b90c3a77f97b7db5e P 2943ecf5581a43f08dbc159290ec0646: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/3c704536954a4a0b90c3a77f97b7db5e/wal-000000015 (ops 71-75)
I20260812 06:18:43.844267 15416 log.cc:1079] T 3c704536954a4a0b90c3a77f97b7db5e P 2943ecf5581a43f08dbc159290ec0646: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/3c704536954a4a0b90c3a77f97b7db5e/wal-000000016 (ops 76-80)
I20260812 06:18:43.844336 15416 log.cc:1079] T 3c704536954a4a0b90c3a77f97b7db5e P 2943ecf5581a43f08dbc159290ec0646: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/3c704536954a4a0b90c3a77f97b7db5e/wal-000000017 (ops 81-85)
I20260812 06:18:43.844400 15416 log.cc:1079] T 3c704536954a4a0b90c3a77f97b7db5e P 2943ecf5581a43f08dbc159290ec0646: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/3c704536954a4a0b90c3a77f97b7db5e/wal-000000018 (ops 86-90)
I20260812 06:18:43.844446 15416 log.cc:1079] T 3c704536954a4a0b90c3a77f97b7db5e P 2943ecf5581a43f08dbc159290ec0646: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/3c704536954a4a0b90c3a77f97b7db5e/wal-000000019 (ops 91-95)
I20260812 06:18:43.844501 15416 log.cc:1079] T 3c704536954a4a0b90c3a77f97b7db5e P 2943ecf5581a43f08dbc159290ec0646: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/3c704536954a4a0b90c3a77f97b7db5e/wal-000000020 (ops 96-100)
I20260812 06:18:43.844540 15416 log.cc:1079] T 3c704536954a4a0b90c3a77f97b7db5e P 2943ecf5581a43f08dbc159290ec0646: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/3c704536954a4a0b90c3a77f97b7db5e/wal-000000021 (ops 101-105)
I20260812 06:18:43.844578 15416 log.cc:1079] T 3c704536954a4a0b90c3a77f97b7db5e P 2943ecf5581a43f08dbc159290ec0646: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/3c704536954a4a0b90c3a77f97b7db5e/wal-000000022 (ops 106-110)
I20260812 06:18:43.844617 15416 log.cc:1079] T 3c704536954a4a0b90c3a77f97b7db5e P 2943ecf5581a43f08dbc159290ec0646: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/3c704536954a4a0b90c3a77f97b7db5e/wal-000000023 (ops 111-114)
I20260812 06:18:43.844661 15416 log.cc:1079] T 3c704536954a4a0b90c3a77f97b7db5e P 2943ecf5581a43f08dbc159290ec0646: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/3c704536954a4a0b90c3a77f97b7db5e/wal-000000024 (ops 115-119)
I20260812 06:18:43.844695 15416 log.cc:1079] T 3c704536954a4a0b90c3a77f97b7db5e P 2943ecf5581a43f08dbc159290ec0646: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/3c704536954a4a0b90c3a77f97b7db5e/wal-000000025 (ops 120-124)
I20260812 06:18:43.844738 15416 log.cc:1079] T 3c704536954a4a0b90c3a77f97b7db5e P 2943ecf5581a43f08dbc159290ec0646: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/3c704536954a4a0b90c3a77f97b7db5e/wal-000000026 (ops 125-128)
I20260812 06:18:43.871827 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: LogGCOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.028s	user 0.004s	sys 0.023s Metrics: {}
I20260812 06:18:43.872249 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=3.181125
I20260812 06:18:43.893930 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.021s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":7487,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:43.894465 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=2.188937
I20260812 06:18:43.906482 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4499,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:43.907260 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling UndoDeltaBlockGCOp(3c704536954a4a0b90c3a77f97b7db5e): 471 bytes on disk
I20260812 06:18:43.907752 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: UndoDeltaBlockGCOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4}
I20260812 06:18:43.908666 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling MajorDeltaCompactionOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=1.000000
I20260812 06:18:44.299933 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: MajorDeltaCompactionOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.391s	user 0.254s	sys 0.116s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979739,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":855,"lbm_read_time_us":24319,"lbm_reads_lt_1ms":774,"lbm_write_time_us":73337,"lbm_writes_lt_1ms":743,"mutex_wait_us":49,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":5888,"thread_start_us":606,"threads_started":6,"update_count":3500}
I20260812 06:18:44.300880 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=18.063937
I20260812 06:18:44.417035 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.116s	user 0.080s	sys 0.035s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":52870,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:44.418412 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=2.188937
I20260812 06:18:44.468834 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.050s	user 0.022s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":12913,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:44.469663 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=2.188937
I20260812 06:18:44.495848 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.026s	user 0.017s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":9265,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:44.497500 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling MajorDeltaCompactionOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=1.000000
I20260812 06:18:44.729601 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: MajorDeltaCompactionOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.232s	user 0.179s	sys 0.052s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32979636,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":657,"lbm_read_time_us":25682,"lbm_reads_lt_1ms":769,"lbm_write_time_us":44173,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":35840,"update_count":3500}
I20260812 06:18:44.730396 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=14.095187
I20260812 06:18:44.780690 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.050s	user 0.021s	sys 0.027s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22527,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:44.781363 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=2.188937
I20260812 06:18:44.803983 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.022s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6926,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:44.804715 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling MajorDeltaCompactionOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=1.000000
I20260812 06:18:44.977362 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: MajorDeltaCompactionOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.172s	user 0.115s	sys 0.053s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":194,"lbm_read_time_us":11797,"lbm_reads_lt_1ms":564,"lbm_write_time_us":32577,"lbm_writes_lt_1ms":543,"mutex_wait_us":67,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":44416,"update_count":2500}
I20260812 06:18:44.978241 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=14.095187
I20260812 06:18:45.028601 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.050s	user 0.029s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20847,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:45.029134 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling MajorDeltaCompactionOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=1.000000
I20260812 06:18:45.181239 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: MajorDeltaCompactionOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.152s	user 0.086s	sys 0.063s 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":684,"lbm_read_time_us":11301,"lbm_reads_lt_1ms":463,"lbm_write_time_us":24134,"lbm_writes_lt_1ms":443,"mutex_wait_us":383,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":22272,"update_count":2000}
I20260812 06:18:45.181977 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=11.118625
I20260812 06:18:45.239317 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.057s	user 0.031s	sys 0.019s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":25995,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":310,"reinsert_count":0,"update_count":1550}
I20260812 06:18:45.239918 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=2.188937
I20260812 06:18:45.258560 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.018s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7046,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:45.259163 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=2.188937
I20260812 06:18:45.270084 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4055,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:45.270807 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling MajorDeltaCompactionOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=1.000000
I20260812 06:18:45.470252 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: MajorDeltaCompactionOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.199s	user 0.118s	sys 0.077s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1271,"lbm_read_time_us":12752,"lbm_reads_lt_1ms":573,"lbm_write_time_us":33975,"lbm_writes_lt_1ms":543,"mutex_wait_us":351,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:18:45.470890 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=11.118625
I20260812 06:18:45.505797 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.035s	user 0.026s	sys 0.005s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14990,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:45.506532 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=2.188937
I20260812 06:18:45.532294 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.026s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5712,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:45.532917 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=2.188937
I20260812 06:18:45.544159 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4355,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:45.544811 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling FlushMRSOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=1.000000
I20260812 06:18:45.573627 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: FlushMRSOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.029s	user 0.027s	sys 0.001s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":85,"dirs.run_cpu_time_us":249,"dirs.run_wall_time_us":1260,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1600,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:45.574402 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling LogGCOp(3c704536954a4a0b90c3a77f97b7db5e): free 112239552 bytes of WAL
I20260812 06:18:45.574699 15416 log_reader.cc:385] T 3c704536954a4a0b90c3a77f97b7db5e: removed 11 log segments from log reader
I20260812 06:18:45.574744 15416 log.cc:1079] T 3c704536954a4a0b90c3a77f97b7db5e P 2943ecf5581a43f08dbc159290ec0646: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/3c704536954a4a0b90c3a77f97b7db5e/wal-000000027 (ops 129-133)
I20260812 06:18:45.574774 15416 log.cc:1079] T 3c704536954a4a0b90c3a77f97b7db5e P 2943ecf5581a43f08dbc159290ec0646: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/3c704536954a4a0b90c3a77f97b7db5e/wal-000000028 (ops 134-138)
I20260812 06:18:45.574834 15416 log.cc:1079] T 3c704536954a4a0b90c3a77f97b7db5e P 2943ecf5581a43f08dbc159290ec0646: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/3c704536954a4a0b90c3a77f97b7db5e/wal-000000029 (ops 139-143)
I20260812 06:18:45.574872 15416 log.cc:1079] T 3c704536954a4a0b90c3a77f97b7db5e P 2943ecf5581a43f08dbc159290ec0646: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/3c704536954a4a0b90c3a77f97b7db5e/wal-000000030 (ops 144-148)
I20260812 06:18:45.574921 15416 log.cc:1079] T 3c704536954a4a0b90c3a77f97b7db5e P 2943ecf5581a43f08dbc159290ec0646: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/3c704536954a4a0b90c3a77f97b7db5e/wal-000000031 (ops 149-152)
I20260812 06:18:45.574962 15416 log.cc:1079] T 3c704536954a4a0b90c3a77f97b7db5e P 2943ecf5581a43f08dbc159290ec0646: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/3c704536954a4a0b90c3a77f97b7db5e/wal-000000032 (ops 153-157)
I20260812 06:18:45.575001 15416 log.cc:1079] T 3c704536954a4a0b90c3a77f97b7db5e P 2943ecf5581a43f08dbc159290ec0646: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/3c704536954a4a0b90c3a77f97b7db5e/wal-000000033 (ops 158-162)
I20260812 06:18:45.575042 15416 log.cc:1079] T 3c704536954a4a0b90c3a77f97b7db5e P 2943ecf5581a43f08dbc159290ec0646: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/3c704536954a4a0b90c3a77f97b7db5e/wal-000000034 (ops 163-167)
I20260812 06:18:45.575080 15416 log.cc:1079] T 3c704536954a4a0b90c3a77f97b7db5e P 2943ecf5581a43f08dbc159290ec0646: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/3c704536954a4a0b90c3a77f97b7db5e/wal-000000035 (ops 168-172)
I20260812 06:18:45.575120 15416 log.cc:1079] T 3c704536954a4a0b90c3a77f97b7db5e P 2943ecf5581a43f08dbc159290ec0646: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/3c704536954a4a0b90c3a77f97b7db5e/wal-000000036 (ops 173-177)
I20260812 06:18:45.575160 15416 log.cc:1079] T 3c704536954a4a0b90c3a77f97b7db5e P 2943ecf5581a43f08dbc159290ec0646: Deleting log segment in path: /tmp/dist-test-taskJmm8tb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515514750243-14921-0/minicluster-data/ts-0-root/wals/3c704536954a4a0b90c3a77f97b7db5e/wal-000000037 (ops 178-182)
I20260812 06:18:45.602072 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: LogGCOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.027s	user 0.001s	sys 0.023s Metrics: {}
I20260812 06:18:45.602561 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=2.188937
I20260812 06:18:45.631381 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.029s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5653,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:45.631965 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=2.188937
I20260812 06:18:45.643537 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4436,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:45.644071 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling MajorDeltaCompactionOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=1.000000
I20260812 06:18:45.899668 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: MajorDeltaCompactionOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.255s	user 0.151s	sys 0.102s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979861,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":241,"lbm_read_time_us":18161,"lbm_reads_lt_1ms":775,"lbm_write_time_us":42065,"lbm_writes_lt_1ms":743,"mutex_wait_us":72,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":92,"threads_started":1,"update_count":3500}
I20260812 06:18:45.900666 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=18.063937
I20260812 06:18:45.975080 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.073s	user 0.035s	sys 0.031s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":32265,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:18:45.975687 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling UndoDeltaBlockGCOp(3c704536954a4a0b90c3a77f97b7db5e): 448 bytes on disk
I20260812 06:18:45.976192 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: UndoDeltaBlockGCOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4}
I20260812 06:18:45.976770 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=2.188937
I20260812 06:18:45.987730 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: FlushDeltaMemStoresOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4207,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:45.988243 15525 maintenance_manager.cc:419] P 2943ecf5581a43f08dbc159290ec0646: Scheduling MajorDeltaCompactionOp(3c704536954a4a0b90c3a77f97b7db5e): perf score=1.000000
I20260812 06:18:46.028646 14921 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.303s	user 1.962s	sys 0.152s
I20260812 06:18:46.101658 14921 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.073s	user 0.001s	sys 0.000s
I20260812 06:18:46.102205 14921 tablet_server.cc:179] TabletServer@127.14.146.65:0 shutting down...
I20260812 06:18:46.169414 15416 maintenance_manager.cc:643] P 2943ecf5581a43f08dbc159290ec0646: MajorDeltaCompactionOp(3c704536954a4a0b90c3a77f97b7db5e) complete. Timing: real 0.181s	user 0.129s	sys 0.052s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":466,"lbm_read_time_us":16217,"lbm_reads_lt_1ms":668,"lbm_write_time_us":31258,"lbm_writes_lt_1ms":643,"mutex_wait_us":24,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":19712,"update_count":3000}
I20260812 06:18:46.170114 14921 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:46.170433 14921 tablet_replica.cc:333] T 3c704536954a4a0b90c3a77f97b7db5e P 2943ecf5581a43f08dbc159290ec0646: stopping tablet replica
I20260812 06:18:46.170576 14921 raft_consensus.cc:2243] T 3c704536954a4a0b90c3a77f97b7db5e P 2943ecf5581a43f08dbc159290ec0646 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:46.170799 14921 raft_consensus.cc:2272] T 3c704536954a4a0b90c3a77f97b7db5e P 2943ecf5581a43f08dbc159290ec0646 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:46.186396 14921 tablet_server.cc:196] TabletServer@127.14.146.65:0 shutdown complete.
I20260812 06:18:46.225989 14921 master.cc:562] Master@127.14.146.126:36337 shutting down...
I20260812 06:18:46.230355 14921 raft_consensus.cc:2243] T 00000000000000000000000000000000 P ef733d18e27f4d968aad8014af16ee8a [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:46.230571 14921 raft_consensus.cc:2272] T 00000000000000000000000000000000 P ef733d18e27f4d968aad8014af16ee8a [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:46.230686 14921 tablet_replica.cc:333] T 00000000000000000000000000000000 P ef733d18e27f4d968aad8014af16ee8a: stopping tablet replica
I20260812 06:18:46.243369 14921 master.cc:584] Master@127.14.146.126:36337 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5825 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11579 ms total)

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