[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:19:37.002091  8682 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.8.122.190:36225
I20260812 06:19:37.003190  8682 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:19:37.003808  8682 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:19:37.010663  8682 server_base.cc:1061] running on GCE node
W20260812 06:19:37.010663  8695 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:37.010813  8698 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:37.010972  8696 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:37.011509  8682 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:37.011693  8682 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:37.011763  8682 hybrid_clock.cc:648] HybridClock initialized: now 1786515577011760 us; error 0 us; skew 500 ppm
I20260812 06:19:37.013660  8682 webserver.cc:533] Webserver started at http://127.8.122.190:40173/ using document root <none> and password file <none>
I20260812 06:19:37.014313  8682 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:37.014377  8682 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:37.014633  8682 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:37.016326  8682 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576990687-8682-0/minicluster-data/master-0-root/instance:
uuid: "563f466c2b6a457dbbd3a74864e0492a"
format_stamp: "Formatted at 2026-08-12 06:19:37 on dist-test-slave-drl0"
I20260812 06:19:37.020470  8682 fs_manager.cc:696] Time spent creating directory manager: real 0.004s	user 0.004s	sys 0.000s
I20260812 06:19:37.023392  8704 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:37.024835  8682 fs_manager.cc:730] Time spent opening block manager: real 0.003s	user 0.003s	sys 0.001s
I20260812 06:19:37.025056  8682 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576990687-8682-0/minicluster-data/master-0-root
uuid: "563f466c2b6a457dbbd3a74864e0492a"
format_stamp: "Formatted at 2026-08-12 06:19:37 on dist-test-slave-drl0"
I20260812 06:19:37.025282  8682 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576990687-8682-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576990687-8682-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576990687-8682-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:37.052591  8682 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:37.053753  8682 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:19:37.054224  8682 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:37.062882  8682 rpc_server.cc:307] RPC server started. Bound to: 127.8.122.190:36225
I20260812 06:19:37.062887  8782 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.8.122.190:36225 every 8 connection(s)
I20260812 06:19:37.066052  8783 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:37.071722  8783 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 563f466c2b6a457dbbd3a74864e0492a: Bootstrap starting.
I20260812 06:19:37.074121  8783 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 563f466c2b6a457dbbd3a74864e0492a: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:37.075090  8783 log.cc:826] T 00000000000000000000000000000000 P 563f466c2b6a457dbbd3a74864e0492a: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:37.077448  8783 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 563f466c2b6a457dbbd3a74864e0492a: No bootstrap required, opened a new log
I20260812 06:19:37.081182  8783 raft_consensus.cc:359] T 00000000000000000000000000000000 P 563f466c2b6a457dbbd3a74864e0492a [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "563f466c2b6a457dbbd3a74864e0492a" member_type: VOTER }
I20260812 06:19:37.081383  8783 raft_consensus.cc:385] T 00000000000000000000000000000000 P 563f466c2b6a457dbbd3a74864e0492a [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:37.081471  8783 raft_consensus.cc:740] T 00000000000000000000000000000000 P 563f466c2b6a457dbbd3a74864e0492a [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 563f466c2b6a457dbbd3a74864e0492a, State: Initialized, Role: FOLLOWER
I20260812 06:19:37.082144  8783 consensus_queue.cc:260] T 00000000000000000000000000000000 P 563f466c2b6a457dbbd3a74864e0492a [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: "563f466c2b6a457dbbd3a74864e0492a" member_type: VOTER }
I20260812 06:19:37.082294  8783 raft_consensus.cc:399] T 00000000000000000000000000000000 P 563f466c2b6a457dbbd3a74864e0492a [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:37.082373  8783 raft_consensus.cc:493] T 00000000000000000000000000000000 P 563f466c2b6a457dbbd3a74864e0492a [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:37.082500  8783 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 563f466c2b6a457dbbd3a74864e0492a [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:37.083966  8783 raft_consensus.cc:515] T 00000000000000000000000000000000 P 563f466c2b6a457dbbd3a74864e0492a [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "563f466c2b6a457dbbd3a74864e0492a" member_type: VOTER }
I20260812 06:19:37.084606  8783 leader_election.cc:304] T 00000000000000000000000000000000 P 563f466c2b6a457dbbd3a74864e0492a [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: 563f466c2b6a457dbbd3a74864e0492a; no voters: 
I20260812 06:19:37.084985  8783 leader_election.cc:290] T 00000000000000000000000000000000 P 563f466c2b6a457dbbd3a74864e0492a [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:37.085186  8788 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 563f466c2b6a457dbbd3a74864e0492a [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:37.085443  8788 raft_consensus.cc:697] T 00000000000000000000000000000000 P 563f466c2b6a457dbbd3a74864e0492a [term 1 LEADER]: Becoming Leader. State: Replica: 563f466c2b6a457dbbd3a74864e0492a, State: Running, Role: LEADER
I20260812 06:19:37.085875  8788 consensus_queue.cc:237] T 00000000000000000000000000000000 P 563f466c2b6a457dbbd3a74864e0492a [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: "563f466c2b6a457dbbd3a74864e0492a" member_type: VOTER }
I20260812 06:19:37.086071  8783 sys_catalog.cc:565] T 00000000000000000000000000000000 P 563f466c2b6a457dbbd3a74864e0492a [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:37.088009  8791 sys_catalog.cc:455] T 00000000000000000000000000000000 P 563f466c2b6a457dbbd3a74864e0492a [sys.catalog]: SysCatalogTable state changed. Reason: New leader 563f466c2b6a457dbbd3a74864e0492a. Latest consensus state: current_term: 1 leader_uuid: "563f466c2b6a457dbbd3a74864e0492a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "563f466c2b6a457dbbd3a74864e0492a" member_type: VOTER } }
I20260812 06:19:37.088125  8791 sys_catalog.cc:458] T 00000000000000000000000000000000 P 563f466c2b6a457dbbd3a74864e0492a [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:37.088095  8789 sys_catalog.cc:455] T 00000000000000000000000000000000 P 563f466c2b6a457dbbd3a74864e0492a [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "563f466c2b6a457dbbd3a74864e0492a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "563f466c2b6a457dbbd3a74864e0492a" member_type: VOTER } }
I20260812 06:19:37.088279  8789 sys_catalog.cc:458] T 00000000000000000000000000000000 P 563f466c2b6a457dbbd3a74864e0492a [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:37.088660  8802 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:37.091393  8802 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:37.091747  8682 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:37.097730  8802 catalog_manager.cc:1383] Generated new cluster ID: 59dac18df2944366ad8cbfc1761ecfe0
I20260812 06:19:37.097811  8802 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:37.120246  8802 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:37.121461  8802 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:37.137930  8802 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 563f466c2b6a457dbbd3a74864e0492a: Generated new TSK 0
I20260812 06:19:37.138726  8802 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:37.157617  8682 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:37.160547  8829 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:37.160575  8822 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:37.160656  8827 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:37.160960  8682 server_base.cc:1061] running on GCE node
I20260812 06:19:37.161167  8682 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:37.161207  8682 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:37.161224  8682 hybrid_clock.cc:648] HybridClock initialized: now 1786515577161224 us; error 0 us; skew 500 ppm
I20260812 06:19:37.162213  8682 webserver.cc:533] Webserver started at http://127.8.122.129:36495/ using document root <none> and password file <none>
I20260812 06:19:37.162408  8682 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:37.162456  8682 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:37.162554  8682 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:37.163018  8682 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576990687-8682-0/minicluster-data/ts-0-root/instance:
uuid: "1aa4b499271043a5a9ca0554bdc3f952"
format_stamp: "Formatted at 2026-08-12 06:19:37 on dist-test-slave-drl0"
I20260812 06:19:37.164934  8682 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.001s
I20260812 06:19:37.166349  8835 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:37.166708  8682 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:37.166810  8682 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576990687-8682-0/minicluster-data/ts-0-root
uuid: "1aa4b499271043a5a9ca0554bdc3f952"
format_stamp: "Formatted at 2026-08-12 06:19:37 on dist-test-slave-drl0"
I20260812 06:19:37.166903  8682 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576990687-8682-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576990687-8682-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576990687-8682-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:37.174750  8682 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:37.175431  8682 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:37.175954  8682 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:37.176810  8682 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:37.176884  8682 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:37.176959  8682 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:37.177012  8682 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:37.185945  8682 rpc_server.cc:307] RPC server started. Bound to: 127.8.122.129:44157
I20260812 06:19:37.186159  8930 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.8.122.129:44157 every 8 connection(s)
I20260812 06:19:37.204035  8933 heartbeater.cc:344] Connected to a master server at 127.8.122.190:36225
I20260812 06:19:37.204466  8933 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:37.205143  8933 heartbeater.cc:507] Master 127.8.122.190:36225 requested a full tablet report, sending...
I20260812 06:19:37.207111  8731 ts_manager.cc:194] Registered new tserver with Master: 1aa4b499271043a5a9ca0554bdc3f952 (127.8.122.129:44157)
I20260812 06:19:37.207921  8682 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.021227202s
I20260812 06:19:37.208431  8731 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:43114
I20260812 06:19:37.219189  8731 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:43124:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:37.236479  8875 tablet_service.cc:1511] Processing CreateTablet for tablet f8181400ba8d40c69503a5078e9a5486 (DEFAULT_TABLE table=heavy-update-compaction-test [id=12d430ad1589430eab9b3bb79a4cb95c]), partition=
I20260812 06:19:37.237573  8875 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet f8181400ba8d40c69503a5078e9a5486. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:37.241374  8954 tablet_bootstrap.cc:492] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952: Bootstrap starting.
I20260812 06:19:37.242688  8954 tablet_bootstrap.cc:654] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:37.244586  8954 tablet_bootstrap.cc:492] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952: No bootstrap required, opened a new log
I20260812 06:19:37.244716  8954 ts_tablet_manager.cc:1403] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952: Time spent bootstrapping tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:19:37.245282  8954 raft_consensus.cc:359] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1aa4b499271043a5a9ca0554bdc3f952" member_type: VOTER last_known_addr { host: "127.8.122.129" port: 44157 } }
I20260812 06:19:37.245391  8954 raft_consensus.cc:385] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:37.245448  8954 raft_consensus.cc:740] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 1aa4b499271043a5a9ca0554bdc3f952, State: Initialized, Role: FOLLOWER
I20260812 06:19:37.245594  8954 consensus_queue.cc:260] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952 [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: "1aa4b499271043a5a9ca0554bdc3f952" member_type: VOTER last_known_addr { host: "127.8.122.129" port: 44157 } }
I20260812 06:19:37.245713  8954 raft_consensus.cc:399] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:37.245764  8954 raft_consensus.cc:493] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:37.245814  8954 raft_consensus.cc:3060] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:37.246583  8954 raft_consensus.cc:515] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1aa4b499271043a5a9ca0554bdc3f952" member_type: VOTER last_known_addr { host: "127.8.122.129" port: 44157 } }
I20260812 06:19:37.246745  8954 leader_election.cc:304] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952 [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: 1aa4b499271043a5a9ca0554bdc3f952; no voters: 
I20260812 06:19:37.247011  8954 leader_election.cc:290] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:37.247116  8956 raft_consensus.cc:2804] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:37.247336  8956 raft_consensus.cc:697] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952 [term 1 LEADER]: Becoming Leader. State: Replica: 1aa4b499271043a5a9ca0554bdc3f952, State: Running, Role: LEADER
I20260812 06:19:37.247395  8954 ts_tablet_manager.cc:1434] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:19:37.247643  8933 heartbeater.cc:499] Master 127.8.122.190:36225 was elected leader, sending a full tablet report...
I20260812 06:19:37.247958  8956 consensus_queue.cc:237] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952 [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: "1aa4b499271043a5a9ca0554bdc3f952" member_type: VOTER last_known_addr { host: "127.8.122.129" port: 44157 } }
I20260812 06:19:37.250684  8731 catalog_manager.cc:5719] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952 reported cstate change: term changed from 0 to 1, leader changed from <none> to 1aa4b499271043a5a9ca0554bdc3f952 (127.8.122.129). New cstate: current_term: 1 leader_uuid: "1aa4b499271043a5a9ca0554bdc3f952" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1aa4b499271043a5a9ca0554bdc3f952" member_type: VOTER last_known_addr { host: "127.8.122.129" port: 44157 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:37.320713  8682 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.062s	user 0.019s	sys 0.007s
I20260812 06:19:37.437242  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling FlushMRSOp(f8181400ba8d40c69503a5078e9a5486): perf score=15.086190
I20260812 06:19:37.634644  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: FlushMRSOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.197s	user 0.139s	sys 0.036s Metrics: {"bytes_written":12307491,"cfile_init":1,"compiler_manager_pool.queue_time_us":242,"delete_count":0,"dirs.queue_time_us":60,"dirs.run_cpu_time_us":178,"dirs.run_wall_time_us":726,"drs_written":1,"lbm_read_time_us":113,"lbm_reads_lt_1ms":4,"lbm_write_time_us":44728,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"thread_start_us":169,"threads_started":1,"update_count":1500}
I20260812 06:19:37.636112  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling LogGCOp(f8181400ba8d40c69503a5078e9a5486): free 20290830 bytes of WAL
I20260812 06:19:37.636493  8844 log_reader.cc:385] T f8181400ba8d40c69503a5078e9a5486: removed 2 log segments from log reader
I20260812 06:19:37.636584  8844 log.cc:1079] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/f8181400ba8d40c69503a5078e9a5486/wal-000000001 (ops 1-6)
I20260812 06:19:37.636660  8844 log.cc:1079] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/f8181400ba8d40c69503a5078e9a5486/wal-000000002 (ops 7-10)
I20260812 06:19:37.641332  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: LogGCOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.005s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:19:37.641687  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486): perf score=2.188937
I20260812 06:19:37.661764  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.020s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6914,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:37.662268  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling UndoDeltaBlockGCOp(f8181400ba8d40c69503a5078e9a5486): 12308962 bytes on disk
I20260812 06:19:37.662839  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: UndoDeltaBlockGCOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4}
I20260812 06:19:37.663343  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling MajorDeltaCompactionOp(f8181400ba8d40c69503a5078e9a5486): perf score=1.000000
I20260812 06:19:37.807687  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: MajorDeltaCompactionOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.144s	user 0.108s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1711,"lbm_read_time_us":9657,"lbm_reads_lt_1ms":460,"lbm_write_time_us":25024,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1152,"thread_start_us":793,"threads_started":5,"update_count":2000}
I20260812 06:19:37.808276  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486): perf score=10.126437
I20260812 06:19:37.842344  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.034s	user 0.024s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15143,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:37.842839  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486): perf score=2.188937
I20260812 06:19:37.859494  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.016s	user 0.015s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6654,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:37.859911  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling MajorDeltaCompactionOp(f8181400ba8d40c69503a5078e9a5486): perf score=1.000000
I20260812 06:19:37.994087  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: MajorDeltaCompactionOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.134s	user 0.106s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":189,"lbm_read_time_us":9919,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26713,"lbm_writes_lt_1ms":443,"mutex_wait_us":52,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11520,"update_count":2000}
I20260812 06:19:37.994757  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486): perf score=10.126437
I20260812 06:19:38.045289  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.050s	user 0.019s	sys 0.020s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":18419,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:38.045831  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486): perf score=2.188937
I20260812 06:19:38.057256  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4294,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:38.057721  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling MajorDeltaCompactionOp(f8181400ba8d40c69503a5078e9a5486): perf score=1.000000
I20260812 06:19:38.206990  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: MajorDeltaCompactionOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.149s	user 0.105s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":642,"lbm_read_time_us":12010,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26140,"lbm_writes_lt_1ms":443,"mutex_wait_us":109,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14976,"update_count":2000}
I20260812 06:19:38.207652  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486): perf score=10.126437
I20260812 06:19:38.264127  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.056s	user 0.025s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17509,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:38.264899  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486): perf score=2.188937
I20260812 06:19:38.282068  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.017s	user 0.013s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6454,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:38.282673  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling MajorDeltaCompactionOp(f8181400ba8d40c69503a5078e9a5486): perf score=1.000000
I20260812 06:19:38.451171  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: MajorDeltaCompactionOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.168s	user 0.102s	sys 0.056s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":173,"lbm_read_time_us":13739,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25971,"lbm_writes_lt_1ms":443,"mutex_wait_us":37,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":20992,"update_count":2000}
I20260812 06:19:38.451761  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486): perf score=10.126437
I20260812 06:19:38.492548  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.041s	user 0.031s	sys 0.008s Metrics: {"bytes_written":12307496,"delete_count":0,"lbm_write_time_us":18423,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:38.493016  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling MajorDeltaCompactionOp(f8181400ba8d40c69503a5078e9a5486): perf score=1.000000
I20260812 06:19:38.614511  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: MajorDeltaCompactionOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.121s	user 0.103s	sys 0.017s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16528787,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":208,"lbm_read_time_us":9021,"lbm_reads_lt_1ms":367,"lbm_write_time_us":20987,"lbm_writes_lt_1ms":343,"mutex_wait_us":51,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":92672,"update_count":1500}
I20260812 06:19:38.615103  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486): perf score=10.126437
I20260812 06:19:38.654448  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.039s	user 0.028s	sys 0.009s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17116,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:38.655090  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling MajorDeltaCompactionOp(f8181400ba8d40c69503a5078e9a5486): perf score=1.000000
I20260812 06:19:38.762069  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: MajorDeltaCompactionOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.107s	user 0.086s	sys 0.020s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16528781,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":410,"lbm_read_time_us":7857,"lbm_reads_lt_1ms":363,"lbm_write_time_us":19958,"lbm_writes_lt_1ms":343,"mutex_wait_us":30,"peak_mem_usage":38262756,"reinsert_count":0,"update_count":1500}
I20260812 06:19:38.762769  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486): perf score=10.126437
I20260812 06:19:38.809489  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.047s	user 0.025s	sys 0.012s Metrics: {"bytes_written":12307494,"delete_count":0,"lbm_write_time_us":16981,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:38.809902  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486): perf score=2.188937
I20260812 06:19:38.820552  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4233,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:38.821010  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling MajorDeltaCompactionOp(f8181400ba8d40c69503a5078e9a5486): perf score=1.000000
I20260812 06:19:38.951874  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: MajorDeltaCompactionOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.131s	user 0.115s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631316,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":232,"lbm_read_time_us":8902,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24992,"lbm_writes_lt_1ms":443,"mutex_wait_us":23,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5376,"update_count":2000}
I20260812 06:19:38.952450  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486): perf score=10.126437
I20260812 06:19:38.996006  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.043s	user 0.019s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15324,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:38.996475  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486): perf score=2.188937
I20260812 06:19:39.006937  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4062,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:39.007676  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling FlushMRSOp(f8181400ba8d40c69503a5078e9a5486): perf score=1.000000
I20260812 06:19:39.039348  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: FlushMRSOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.031s	user 0.027s	sys 0.004s Metrics: {"bytes_written":1234474,"cfile_init":1,"dirs.queue_time_us":61,"dirs.run_cpu_time_us":239,"dirs.run_wall_time_us":1168,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1859,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:39.040205  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling LogGCOp(f8181400ba8d40c69503a5078e9a5486): free 112692313 bytes of WAL
I20260812 06:19:39.040429  8844 log_reader.cc:385] T f8181400ba8d40c69503a5078e9a5486: removed 11 log segments from log reader
I20260812 06:19:39.040472  8844 log.cc:1079] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/f8181400ba8d40c69503a5078e9a5486/wal-000000003 (ops 11-15)
I20260812 06:19:39.040501  8844 log.cc:1079] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/f8181400ba8d40c69503a5078e9a5486/wal-000000004 (ops 16-20)
I20260812 06:19:39.040566  8844 log.cc:1079] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/f8181400ba8d40c69503a5078e9a5486/wal-000000005 (ops 21-25)
I20260812 06:19:39.040612  8844 log.cc:1079] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/f8181400ba8d40c69503a5078e9a5486/wal-000000006 (ops 26-30)
I20260812 06:19:39.040654  8844 log.cc:1079] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/f8181400ba8d40c69503a5078e9a5486/wal-000000007 (ops 31-35)
I20260812 06:19:39.040711  8844 log.cc:1079] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/f8181400ba8d40c69503a5078e9a5486/wal-000000008 (ops 36-40)
I20260812 06:19:39.040750  8844 log.cc:1079] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/f8181400ba8d40c69503a5078e9a5486/wal-000000009 (ops 41-45)
I20260812 06:19:39.040791  8844 log.cc:1079] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/f8181400ba8d40c69503a5078e9a5486/wal-000000010 (ops 46-50)
I20260812 06:19:39.040831  8844 log.cc:1079] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/f8181400ba8d40c69503a5078e9a5486/wal-000000011 (ops 51-55)
I20260812 06:19:39.040872  8844 log.cc:1079] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/f8181400ba8d40c69503a5078e9a5486/wal-000000012 (ops 56-60)
I20260812 06:19:39.040916  8844 log.cc:1079] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/f8181400ba8d40c69503a5078e9a5486/wal-000000013 (ops 61-65)
I20260812 06:19:39.069099  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: LogGCOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.029s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:19:39.069792  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486): perf score=3.181125
I20260812 06:19:39.088900  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.019s	user 0.017s	sys 0.000s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":7335,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:39.089612  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling LogGCOp(f8181400ba8d40c69503a5078e9a5486): free 12017983 bytes of WAL
I20260812 06:19:39.089869  8844 log_reader.cc:385] T f8181400ba8d40c69503a5078e9a5486: removed 1 log segments from log reader
I20260812 06:19:39.089939  8844 log.cc:1079] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/f8181400ba8d40c69503a5078e9a5486/wal-000000014 (ops 66-70)
I20260812 06:19:39.093201  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: LogGCOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:19:39.093835  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling UndoDeltaBlockGCOp(f8181400ba8d40c69503a5078e9a5486): 472 bytes on disk
I20260812 06:19:39.094291  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: UndoDeltaBlockGCOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:19:39.094732  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486): perf score=2.188937
I20260812 06:19:39.105813  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.011s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3996,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:39.106262  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling MajorDeltaCompactionOp(f8181400ba8d40c69503a5078e9a5486): perf score=1.000000
I20260812 06:19:39.288765  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: MajorDeltaCompactionOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.182s	user 0.150s	sys 0.031s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836360,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":311,"lbm_read_time_us":12378,"lbm_reads_lt_1ms":674,"lbm_write_time_us":36895,"lbm_writes_lt_1ms":643,"mutex_wait_us":702,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":45696,"thread_start_us":75,"threads_started":1,"update_count":3000}
I20260812 06:19:39.290772  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486): perf score=14.095187
I20260812 06:19:39.353293  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.062s	user 0.025s	sys 0.035s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":29204,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:39.353863  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486): perf score=2.188937
I20260812 06:19:39.372637  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.019s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6753,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:39.373121  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling MajorDeltaCompactionOp(f8181400ba8d40c69503a5078e9a5486): perf score=1.000000
I20260812 06:19:39.541627  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: MajorDeltaCompactionOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.168s	user 0.135s	sys 0.024s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733725,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":535,"lbm_read_time_us":12004,"lbm_reads_lt_1ms":568,"lbm_write_time_us":32318,"lbm_writes_lt_1ms":543,"mutex_wait_us":45,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":38016,"update_count":2500}
I20260812 06:19:39.542227  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486): perf score=14.095187
I20260812 06:19:39.597893  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.055s	user 0.034s	sys 0.017s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":25927,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:39.598479  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486): perf score=2.188937
I20260812 06:19:39.614711  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.016s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6273,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:39.615193  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling MajorDeltaCompactionOp(f8181400ba8d40c69503a5078e9a5486): perf score=1.000000
I20260812 06:19:39.773440  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: MajorDeltaCompactionOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.158s	user 0.123s	sys 0.035s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733727,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":144,"lbm_read_time_us":10957,"lbm_reads_lt_1ms":564,"lbm_write_time_us":34096,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13056,"update_count":2500}
I20260812 06:19:39.774454  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486): perf score=14.095187
I20260812 06:19:39.824131  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.049s	user 0.025s	sys 0.024s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":21906,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:39.824597  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486): perf score=2.188937
I20260812 06:19:39.837875  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.013s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4814,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:39.838419  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling MajorDeltaCompactionOp(f8181400ba8d40c69503a5078e9a5486): perf score=1.000000
I20260812 06:19:39.998967  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: MajorDeltaCompactionOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.160s	user 0.134s	sys 0.019s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733722,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":919,"lbm_read_time_us":11228,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28614,"lbm_writes_lt_1ms":543,"mutex_wait_us":337,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2500}
I20260812 06:19:39.999823  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486): perf score=14.095187
I20260812 06:19:40.049525  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.050s	user 0.032s	sys 0.015s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21902,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:40.050065  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling MajorDeltaCompactionOp(f8181400ba8d40c69503a5078e9a5486): perf score=1.000000
I20260812 06:19:40.207185  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: MajorDeltaCompactionOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.157s	user 0.113s	sys 0.040s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20631193,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":396,"lbm_read_time_us":11255,"lbm_reads_lt_1ms":467,"lbm_write_time_us":26156,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3712,"update_count":2000}
I20260812 06:19:40.207877  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486): perf score=11.118625
I20260812 06:19:40.251703  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.044s	user 0.039s	sys 0.004s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":18775,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:40.252731  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486): perf score=2.188937
I20260812 06:19:40.281234  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.028s	user 0.004s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5648,"lbm_writes_lt_1ms":93,"mutex_wait_us":50,"reinsert_count":0,"update_count":450}
I20260812 06:19:40.281740  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486): perf score=2.188937
I20260812 06:19:40.293102  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4573,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:40.293574  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling MajorDeltaCompactionOp(f8181400ba8d40c69503a5078e9a5486): perf score=1.000000
I20260812 06:19:40.515550  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: MajorDeltaCompactionOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.222s	user 0.139s	sys 0.068s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733833,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":330,"lbm_read_time_us":16329,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30175,"lbm_writes_lt_1ms":543,"mutex_wait_us":101,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11008,"update_count":2500}
I20260812 06:19:40.516757  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486): perf score=14.095187
I20260812 06:19:40.568460  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.051s	user 0.022s	sys 0.028s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":20892,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:40.568953  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486): perf score=2.188937
I20260812 06:19:40.592566  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.023s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6128,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:40.593343  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling FlushMRSOp(f8181400ba8d40c69503a5078e9a5486): perf score=1.000000
I20260812 06:19:40.634268  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: FlushMRSOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.040s	user 0.034s	sys 0.003s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":76,"dirs.run_cpu_time_us":177,"dirs.run_wall_time_us":1082,"drs_written":1,"lbm_read_time_us":78,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1906,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:40.635567  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling LogGCOp(f8181400ba8d40c69503a5078e9a5486): free 117302573 bytes of WAL
I20260812 06:19:40.635885  8844 log_reader.cc:385] T f8181400ba8d40c69503a5078e9a5486: removed 12 log segments from log reader
I20260812 06:19:40.635994  8844 log.cc:1079] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/f8181400ba8d40c69503a5078e9a5486/wal-000000015 (ops 71-75)
I20260812 06:19:40.636114  8844 log.cc:1079] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/f8181400ba8d40c69503a5078e9a5486/wal-000000016 (ops 76-80)
I20260812 06:19:40.636291  8844 log.cc:1079] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/f8181400ba8d40c69503a5078e9a5486/wal-000000017 (ops 81-85)
I20260812 06:19:40.636386  8844 log.cc:1079] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/f8181400ba8d40c69503a5078e9a5486/wal-000000018 (ops 86-90)
I20260812 06:19:40.636474  8844 log.cc:1079] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/f8181400ba8d40c69503a5078e9a5486/wal-000000019 (ops 91-95)
I20260812 06:19:40.636559  8844 log.cc:1079] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/f8181400ba8d40c69503a5078e9a5486/wal-000000020 (ops 96-100)
I20260812 06:19:40.636652  8844 log.cc:1079] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/f8181400ba8d40c69503a5078e9a5486/wal-000000021 (ops 101-104)
I20260812 06:19:40.636741  8844 log.cc:1079] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/f8181400ba8d40c69503a5078e9a5486/wal-000000022 (ops 105-109)
I20260812 06:19:40.636842  8844 log.cc:1079] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/f8181400ba8d40c69503a5078e9a5486/wal-000000023 (ops 110-114)
I20260812 06:19:40.636926  8844 log.cc:1079] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/f8181400ba8d40c69503a5078e9a5486/wal-000000024 (ops 115-118)
I20260812 06:19:40.637022  8844 log.cc:1079] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/f8181400ba8d40c69503a5078e9a5486/wal-000000025 (ops 119-123)
I20260812 06:19:40.637104  8844 log.cc:1079] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/f8181400ba8d40c69503a5078e9a5486/wal-000000026 (ops 124-128)
I20260812 06:19:40.670079  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: LogGCOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.034s	user 0.000s	sys 0.031s Metrics: {}
I20260812 06:19:40.670826  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling UndoDeltaBlockGCOp(f8181400ba8d40c69503a5078e9a5486): 483 bytes on disk
I20260812 06:19:40.671564  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: UndoDeltaBlockGCOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4}
I20260812 06:19:40.672258  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486): perf score=3.181125
I20260812 06:19:40.695254  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.023s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":5694,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:40.695935  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486): perf score=2.188937
I20260812 06:19:40.707792  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4493,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:40.708307  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling MajorDeltaCompactionOp(f8181400ba8d40c69503a5078e9a5486): perf score=1.000000
I20260812 06:19:41.006057  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: MajorDeltaCompactionOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.298s	user 0.197s	sys 0.096s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32938769,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":738,"lbm_read_time_us":19491,"lbm_reads_lt_1ms":774,"lbm_write_time_us":48024,"lbm_writes_lt_1ms":743,"mutex_wait_us":112,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":22400,"thread_start_us":114,"threads_started":1,"update_count":3500}
I20260812 06:19:41.007997  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486): perf score=16.079562
I20260812 06:19:41.094246  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.083s	user 0.046s	sys 0.018s Metrics: {"bytes_written":18748276,"delete_count":0,"lbm_write_time_us":31217,"lbm_writes_lt_1ms":460,"reinsert_count":0,"update_count":2285}
I20260812 06:19:41.094816  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486): perf score=4.173312
I20260812 06:19:41.112496  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.017s	user 0.011s	sys 0.005s Metrics: {"bytes_written":5866708,"delete_count":0,"lbm_write_time_us":6311,"lbm_writes_lt_1ms":146,"reinsert_count":0,"update_count":715}
I20260812 06:19:41.113204  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling MajorDeltaCompactionOp(f8181400ba8d40c69503a5078e9a5486): perf score=1.000000
I20260812 06:19:41.325361  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: MajorDeltaCompactionOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.212s	user 0.160s	sys 0.052s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28836141,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":261,"lbm_read_time_us":15316,"lbm_reads_lt_1ms":672,"lbm_write_time_us":34262,"lbm_writes_lt_1ms":643,"mutex_wait_us":45,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":13568,"update_count":3000}
I20260812 06:19:41.326122  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486): perf score=14.095187
I20260812 06:19:41.400333  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.074s	user 0.041s	sys 0.013s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25645,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":1752320,"update_count":2000}
I20260812 06:19:41.400894  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486): perf score=2.188937
I20260812 06:19:41.417238  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.014s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5138,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:41.418040  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling MajorDeltaCompactionOp(f8181400ba8d40c69503a5078e9a5486): perf score=1.000000
I20260812 06:19:41.635119  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: MajorDeltaCompactionOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.216s	user 0.149s	sys 0.057s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":2539,"lbm_read_time_us":14775,"lbm_reads_lt_1ms":572,"lbm_write_time_us":37004,"lbm_writes_lt_1ms":543,"mutex_wait_us":1443,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:41.636711  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486): perf score=14.095187
I20260812 06:19:41.706820  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.070s	user 0.034s	sys 0.031s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":25122,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:41.707456  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486): perf score=2.188937
I20260812 06:19:41.722394  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.015s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5590,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:41.722913  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling MajorDeltaCompactionOp(f8181400ba8d40c69503a5078e9a5486): perf score=1.000000
I20260812 06:19:41.909554  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: MajorDeltaCompactionOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.186s	user 0.128s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":822,"lbm_read_time_us":15275,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28994,"lbm_writes_lt_1ms":543,"mutex_wait_us":448,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8448,"update_count":2500}
I20260812 06:19:41.910339  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486): perf score=10.126437
I20260812 06:19:41.967502  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.056s	user 0.040s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18877,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:41.967990  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486): perf score=2.188937
I20260812 06:19:41.990856  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.023s	user 0.011s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4878,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:41.991447  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling MajorDeltaCompactionOp(f8181400ba8d40c69503a5078e9a5486): perf score=1.000000
I20260812 06:19:42.197315  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: MajorDeltaCompactionOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.206s	user 0.135s	sys 0.053s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":122,"lbm_read_time_us":11542,"lbm_reads_lt_1ms":472,"lbm_write_time_us":31833,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:42.198086  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486): perf score=10.126437
I20260812 06:19:42.262727  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.064s	user 0.021s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20617,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:42.263581  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486): perf score=2.188937
I20260812 06:19:42.280288  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.016s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6001,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:42.281200  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling MajorDeltaCompactionOp(f8181400ba8d40c69503a5078e9a5486): perf score=1.000000
I20260812 06:19:42.418515  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: MajorDeltaCompactionOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.137s	user 0.100s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":151,"lbm_read_time_us":9145,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25548,"lbm_writes_lt_1ms":443,"mutex_wait_us":45,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7552,"update_count":2000}
I20260812 06:19:42.419305  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486): perf score=10.126437
I20260812 06:19:42.474835  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.055s	user 0.022s	sys 0.021s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20356,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:42.475425  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486): perf score=2.188937
I20260812 06:19:42.487164  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4456,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:42.487679  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling FlushMRSOp(f8181400ba8d40c69503a5078e9a5486): perf score=1.000000
I20260812 06:19:42.524693  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: FlushMRSOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.037s	user 0.035s	sys 0.000s Metrics: {"bytes_written":1234477,"cfile_init":1,"dirs.queue_time_us":72,"dirs.run_cpu_time_us":178,"dirs.run_wall_time_us":1252,"drs_written":1,"lbm_read_time_us":84,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2251,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:42.525492  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling LogGCOp(f8181400ba8d40c69503a5078e9a5486): free 124257509 bytes of WAL
I20260812 06:19:42.525698  8844 log_reader.cc:385] T f8181400ba8d40c69503a5078e9a5486: removed 12 log segments from log reader
I20260812 06:19:42.525748  8844 log.cc:1079] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/f8181400ba8d40c69503a5078e9a5486/wal-000000027 (ops 129-133)
I20260812 06:19:42.525844  8844 log.cc:1079] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/f8181400ba8d40c69503a5078e9a5486/wal-000000028 (ops 134-138)
I20260812 06:19:42.525883  8844 log.cc:1079] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/f8181400ba8d40c69503a5078e9a5486/wal-000000029 (ops 139-143)
I20260812 06:19:42.525909  8844 log.cc:1079] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/f8181400ba8d40c69503a5078e9a5486/wal-000000030 (ops 144-148)
I20260812 06:19:42.525942  8844 log.cc:1079] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/f8181400ba8d40c69503a5078e9a5486/wal-000000031 (ops 149-153)
I20260812 06:19:42.526002  8844 log.cc:1079] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/f8181400ba8d40c69503a5078e9a5486/wal-000000032 (ops 154-158)
I20260812 06:19:42.526037  8844 log.cc:1079] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/f8181400ba8d40c69503a5078e9a5486/wal-000000033 (ops 159-163)
I20260812 06:19:42.526094  8844 log.cc:1079] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/f8181400ba8d40c69503a5078e9a5486/wal-000000034 (ops 164-168)
I20260812 06:19:42.526134  8844 log.cc:1079] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/f8181400ba8d40c69503a5078e9a5486/wal-000000035 (ops 169-173)
I20260812 06:19:42.526188  8844 log.cc:1079] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/f8181400ba8d40c69503a5078e9a5486/wal-000000036 (ops 174-178)
I20260812 06:19:42.526223  8844 log.cc:1079] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/f8181400ba8d40c69503a5078e9a5486/wal-000000037 (ops 179-182)
I20260812 06:19:42.526279  8844 log.cc:1079] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/f8181400ba8d40c69503a5078e9a5486/wal-000000038 (ops 183-187)
I20260812 06:19:42.559646  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: LogGCOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.034s	user 0.000s	sys 0.033s Metrics: {}
I20260812 06:19:42.560171  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling UndoDeltaBlockGCOp(f8181400ba8d40c69503a5078e9a5486): 472 bytes on disk
I20260812 06:19:42.560699  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: UndoDeltaBlockGCOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4}
I20260812 06:19:42.561360  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486): perf score=3.181125
I20260812 06:19:42.586815  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.025s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":6408,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:42.587456  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling LogGCOp(f8181400ba8d40c69503a5078e9a5486): free 12017952 bytes of WAL
I20260812 06:19:42.587694  8844 log_reader.cc:385] T f8181400ba8d40c69503a5078e9a5486: removed 1 log segments from log reader
I20260812 06:19:42.587765  8844 log.cc:1079] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/f8181400ba8d40c69503a5078e9a5486/wal-000000039 (ops 188-192)
I20260812 06:19:42.590441  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: LogGCOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.003s	user 0.001s	sys 0.000s Metrics: {}
I20260812 06:19:42.591099  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486): perf score=2.188937
I20260812 06:19:42.603338  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4459,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:42.603912  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling MajorDeltaCompactionOp(f8181400ba8d40c69503a5078e9a5486): perf score=1.000000
I20260812 06:19:42.801265  8682 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.480s	user 2.000s	sys 0.147s
I20260812 06:19:42.806110  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: MajorDeltaCompactionOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.202s	user 0.154s	sys 0.032s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836360,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":3790,"lbm_read_time_us":13520,"lbm_reads_lt_1ms":674,"lbm_write_time_us":38639,"lbm_writes_lt_1ms":643,"mutex_wait_us":2857,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":96,"threads_started":1,"update_count":3000}
I20260812 06:19:42.806842  8934 maintenance_manager.cc:419] P 1aa4b499271043a5a9ca0554bdc3f952: Scheduling FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486): perf score=14.095187
I20260812 06:19:42.837633  8682 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.036s	user 0.003s	sys 0.000s
I20260812 06:19:42.838370  8682 tablet_server.cc:179] TabletServer@127.8.122.129:0 shutting down...
I20260812 06:19:42.862246  8844 maintenance_manager.cc:643] P 1aa4b499271043a5a9ca0554bdc3f952: FlushDeltaMemStoresOp(f8181400ba8d40c69503a5078e9a5486) complete. Timing: real 0.055s	user 0.025s	sys 0.026s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":24765,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:42.862973  8682 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:42.863510  8682 tablet_replica.cc:333] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952: stopping tablet replica
I20260812 06:19:42.863765  8682 raft_consensus.cc:2243] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:42.864022  8682 raft_consensus.cc:2272] T f8181400ba8d40c69503a5078e9a5486 P 1aa4b499271043a5a9ca0554bdc3f952 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:42.879609  8682 tablet_server.cc:196] TabletServer@127.8.122.129:0 shutdown complete.
I20260812 06:19:42.885771  8682 master.cc:562] Master@127.8.122.190:36225 shutting down...
I20260812 06:19:42.890796  8682 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 563f466c2b6a457dbbd3a74864e0492a [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:42.891011  8682 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 563f466c2b6a457dbbd3a74864e0492a [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:42.891084  8682 tablet_replica.cc:333] T 00000000000000000000000000000000 P 563f466c2b6a457dbbd3a74864e0492a: stopping tablet replica
I20260812 06:19:42.905187  8682 master.cc:584] Master@127.8.122.190:36225 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (6022 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:43.024385  8682 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.8.122.190:33655
I20260812 06:19:43.024816  8682 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:43.027493  8978 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:43.027714  8980 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:43.027824  8682 server_base.cc:1061] running on GCE node
W20260812 06:19:43.027948  8983 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:43.028198  8682 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:43.028241  8682 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:43.028258  8682 hybrid_clock.cc:648] HybridClock initialized: now 1786515583028258 us; error 0 us; skew 500 ppm
I20260812 06:19:43.029181  8682 webserver.cc:533] Webserver started at http://127.8.122.190:36307/ using document root <none> and password file <none>
I20260812 06:19:43.029489  8682 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:43.029548  8682 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:43.029651  8682 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:43.030576  8682 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576990687-8682-0/minicluster-data/master-0-root/instance:
uuid: "747a3fe2b0c74a2bb2117315f4291c60"
format_stamp: "Formatted at 2026-08-12 06:19:43 on dist-test-slave-drl0"
I20260812 06:19:43.032595  8682 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:19:43.033753  8990 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:43.034078  8682 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:43.034184  8682 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576990687-8682-0/minicluster-data/master-0-root
uuid: "747a3fe2b0c74a2bb2117315f4291c60"
format_stamp: "Formatted at 2026-08-12 06:19:43 on dist-test-slave-drl0"
I20260812 06:19:43.034288  8682 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576990687-8682-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576990687-8682-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576990687-8682-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:43.041014  8682 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:43.041368  8682 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:43.045887  8682 rpc_server.cc:307] RPC server started. Bound to: 127.8.122.190:33655
I20260812 06:19:43.051278  9067 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.8.122.190:33655 every 8 connection(s)
I20260812 06:19:43.065732  9068 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:43.068239  9068 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 747a3fe2b0c74a2bb2117315f4291c60: Bootstrap starting.
I20260812 06:19:43.069190  9068 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 747a3fe2b0c74a2bb2117315f4291c60: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:43.070827  9068 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 747a3fe2b0c74a2bb2117315f4291c60: No bootstrap required, opened a new log
I20260812 06:19:43.071303  9068 raft_consensus.cc:359] T 00000000000000000000000000000000 P 747a3fe2b0c74a2bb2117315f4291c60 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "747a3fe2b0c74a2bb2117315f4291c60" member_type: VOTER }
I20260812 06:19:43.071414  9068 raft_consensus.cc:385] T 00000000000000000000000000000000 P 747a3fe2b0c74a2bb2117315f4291c60 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:43.071444  9068 raft_consensus.cc:740] T 00000000000000000000000000000000 P 747a3fe2b0c74a2bb2117315f4291c60 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 747a3fe2b0c74a2bb2117315f4291c60, State: Initialized, Role: FOLLOWER
I20260812 06:19:43.071578  9068 consensus_queue.cc:260] T 00000000000000000000000000000000 P 747a3fe2b0c74a2bb2117315f4291c60 [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: "747a3fe2b0c74a2bb2117315f4291c60" member_type: VOTER }
I20260812 06:19:43.071664  9068 raft_consensus.cc:399] T 00000000000000000000000000000000 P 747a3fe2b0c74a2bb2117315f4291c60 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:43.071694  9068 raft_consensus.cc:493] T 00000000000000000000000000000000 P 747a3fe2b0c74a2bb2117315f4291c60 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:43.071732  9068 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 747a3fe2b0c74a2bb2117315f4291c60 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:43.072754  9068 raft_consensus.cc:515] T 00000000000000000000000000000000 P 747a3fe2b0c74a2bb2117315f4291c60 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "747a3fe2b0c74a2bb2117315f4291c60" member_type: VOTER }
I20260812 06:19:43.072921  9068 leader_election.cc:304] T 00000000000000000000000000000000 P 747a3fe2b0c74a2bb2117315f4291c60 [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: 747a3fe2b0c74a2bb2117315f4291c60; no voters: 
I20260812 06:19:43.073122  9068 leader_election.cc:290] T 00000000000000000000000000000000 P 747a3fe2b0c74a2bb2117315f4291c60 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:43.073318  9073 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 747a3fe2b0c74a2bb2117315f4291c60 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:43.073558  9073 raft_consensus.cc:697] T 00000000000000000000000000000000 P 747a3fe2b0c74a2bb2117315f4291c60 [term 1 LEADER]: Becoming Leader. State: Replica: 747a3fe2b0c74a2bb2117315f4291c60, State: Running, Role: LEADER
I20260812 06:19:43.073601  9068 sys_catalog.cc:565] T 00000000000000000000000000000000 P 747a3fe2b0c74a2bb2117315f4291c60 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:43.073772  9073 consensus_queue.cc:237] T 00000000000000000000000000000000 P 747a3fe2b0c74a2bb2117315f4291c60 [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: "747a3fe2b0c74a2bb2117315f4291c60" member_type: VOTER }
I20260812 06:19:43.074486  9075 sys_catalog.cc:455] T 00000000000000000000000000000000 P 747a3fe2b0c74a2bb2117315f4291c60 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 747a3fe2b0c74a2bb2117315f4291c60. Latest consensus state: current_term: 1 leader_uuid: "747a3fe2b0c74a2bb2117315f4291c60" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "747a3fe2b0c74a2bb2117315f4291c60" member_type: VOTER } }
I20260812 06:19:43.074581  9075 sys_catalog.cc:458] T 00000000000000000000000000000000 P 747a3fe2b0c74a2bb2117315f4291c60 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:43.074790  9074 sys_catalog.cc:455] T 00000000000000000000000000000000 P 747a3fe2b0c74a2bb2117315f4291c60 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "747a3fe2b0c74a2bb2117315f4291c60" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "747a3fe2b0c74a2bb2117315f4291c60" member_type: VOTER } }
I20260812 06:19:43.074908  9074 sys_catalog.cc:458] T 00000000000000000000000000000000 P 747a3fe2b0c74a2bb2117315f4291c60 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:43.075153  9086 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:43.076047  9086 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:43.076242  8682 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:43.078019  9086 catalog_manager.cc:1383] Generated new cluster ID: 940e8e6c47914bea860bb14a4db680be
I20260812 06:19:43.078075  9086 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:43.085574  9086 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:43.086436  9086 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:43.095547  9086 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 747a3fe2b0c74a2bb2117315f4291c60: Generated new TSK 0
I20260812 06:19:43.095804  9086 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:43.108966  8682 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:43.111573  9100 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:43.111639  9102 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:43.111677  9099 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:43.111814  8682 server_base.cc:1061] running on GCE node
I20260812 06:19:43.112448  8682 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:43.112529  8682 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:43.112558  8682 hybrid_clock.cc:648] HybridClock initialized: now 1786515583112557 us; error 0 us; skew 500 ppm
I20260812 06:19:43.113816  8682 webserver.cc:533] Webserver started at http://127.8.122.129:35693/ using document root <none> and password file <none>
I20260812 06:19:43.114188  8682 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:43.114310  8682 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:43.114614  8682 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:43.115234  8682 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576990687-8682-0/minicluster-data/ts-0-root/instance:
uuid: "d1e974c921d54afbb277e96a7d9f21cb"
format_stamp: "Formatted at 2026-08-12 06:19:43 on dist-test-slave-drl0"
I20260812 06:19:43.117276  8682 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:43.118553  9107 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:43.118877  8682 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:43.118997  8682 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576990687-8682-0/minicluster-data/ts-0-root
uuid: "d1e974c921d54afbb277e96a7d9f21cb"
format_stamp: "Formatted at 2026-08-12 06:19:43 on dist-test-slave-drl0"
I20260812 06:19:43.119093  8682 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576990687-8682-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576990687-8682-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576990687-8682-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:43.142258  8682 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:43.142891  8682 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:43.143401  8682 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:43.144042  8682 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:43.144109  8682 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:43.144167  8682 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:43.144219  8682 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:43.150769  8682 rpc_server.cc:307] RPC server started. Bound to: 127.8.122.129:37127
I20260812 06:19:43.150774  9198 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.8.122.129:37127 every 8 connection(s)
I20260812 06:19:43.161258  9199 heartbeater.cc:344] Connected to a master server at 127.8.122.190:33655
I20260812 06:19:43.161404  9199 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:43.161681  9199 heartbeater.cc:507] Master 127.8.122.190:33655 requested a full tablet report, sending...
I20260812 06:19:43.162405  9011 ts_manager.cc:194] Registered new tserver with Master: d1e974c921d54afbb277e96a7d9f21cb (127.8.122.129:37127)
I20260812 06:19:43.162776  8682 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011437998s
I20260812 06:19:43.163589  9011 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:39002
I20260812 06:19:43.171335  9011 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:39010:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:43.181362  9151 tablet_service.cc:1511] Processing CreateTablet for tablet 54917fe44c344fb0a27cc5ce138586d8 (DEFAULT_TABLE table=heavy-update-compaction-test [id=e59ec01f81f14830ba745ad64662ad24]), partition=
I20260812 06:19:43.181653  9151 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 54917fe44c344fb0a27cc5ce138586d8. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:43.184063  9213 tablet_bootstrap.cc:492] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb: Bootstrap starting.
I20260812 06:19:43.185130  9213 tablet_bootstrap.cc:654] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:43.186410  9213 tablet_bootstrap.cc:492] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb: No bootstrap required, opened a new log
I20260812 06:19:43.186504  9213 ts_tablet_manager.cc:1403] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:43.187023  9213 raft_consensus.cc:359] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d1e974c921d54afbb277e96a7d9f21cb" member_type: VOTER last_known_addr { host: "127.8.122.129" port: 37127 } }
I20260812 06:19:43.187137  9213 raft_consensus.cc:385] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:43.187284  9213 raft_consensus.cc:740] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: d1e974c921d54afbb277e96a7d9f21cb, State: Initialized, Role: FOLLOWER
I20260812 06:19:43.187649  9213 consensus_queue.cc:260] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb [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: "d1e974c921d54afbb277e96a7d9f21cb" member_type: VOTER last_known_addr { host: "127.8.122.129" port: 37127 } }
I20260812 06:19:43.187798  9213 raft_consensus.cc:399] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:43.187837  9213 raft_consensus.cc:493] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:43.187883  9213 raft_consensus.cc:3060] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:43.189172  9213 raft_consensus.cc:515] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d1e974c921d54afbb277e96a7d9f21cb" member_type: VOTER last_known_addr { host: "127.8.122.129" port: 37127 } }
I20260812 06:19:43.189333  9213 leader_election.cc:304] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb [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: d1e974c921d54afbb277e96a7d9f21cb; no voters: 
I20260812 06:19:43.189534  9213 leader_election.cc:290] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:43.189675  9215 raft_consensus.cc:2804] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:43.189929  9215 raft_consensus.cc:697] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb [term 1 LEADER]: Becoming Leader. State: Replica: d1e974c921d54afbb277e96a7d9f21cb, State: Running, Role: LEADER
I20260812 06:19:43.189986  9213 ts_tablet_manager.cc:1434] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb: Time spent starting tablet: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:19:43.190114  9215 consensus_queue.cc:237] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb [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: "d1e974c921d54afbb277e96a7d9f21cb" member_type: VOTER last_known_addr { host: "127.8.122.129" port: 37127 } }
I20260812 06:19:43.190207  9199 heartbeater.cc:499] Master 127.8.122.190:33655 was elected leader, sending a full tablet report...
I20260812 06:19:43.191577  9011 catalog_manager.cc:5719] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb reported cstate change: term changed from 0 to 1, leader changed from <none> to d1e974c921d54afbb277e96a7d9f21cb (127.8.122.129). New cstate: current_term: 1 leader_uuid: "d1e974c921d54afbb277e96a7d9f21cb" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d1e974c921d54afbb277e96a7d9f21cb" member_type: VOTER last_known_addr { host: "127.8.122.129" port: 37127 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:43.258872  8682 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.061s	user 0.012s	sys 0.012s
I20260812 06:19:43.401815  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling FlushMRSOp(54917fe44c344fb0a27cc5ce138586d8): perf score=15.086190
I20260812 06:19:43.557782  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: FlushMRSOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.156s	user 0.099s	sys 0.053s Metrics: {"bytes_written":11897249,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":78,"dirs.run_cpu_time_us":207,"dirs.run_wall_time_us":774,"drs_written":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4,"lbm_write_time_us":42827,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1450}
I20260812 06:19:43.558686  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling LogGCOp(54917fe44c344fb0a27cc5ce138586d8): free 20743880 bytes of WAL
I20260812 06:19:43.559005  9116 log_reader.cc:385] T 54917fe44c344fb0a27cc5ce138586d8: removed 2 log segments from log reader
I20260812 06:19:43.559067  9116 log.cc:1079] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/54917fe44c344fb0a27cc5ce138586d8/wal-000000001 (ops 1-6)
I20260812 06:19:43.559113  9116 log.cc:1079] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/54917fe44c344fb0a27cc5ce138586d8/wal-000000002 (ops 7-11)
I20260812 06:19:43.565241  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: LogGCOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.006s	user 0.001s	sys 0.003s Metrics: {}
I20260812 06:19:43.565608  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling UndoDeltaBlockGCOp(54917fe44c344fb0a27cc5ce138586d8): 12719216 bytes on disk
I20260812 06:19:43.566056  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: UndoDeltaBlockGCOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4}
I20260812 06:19:43.566480  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8): perf score=2.188937
I20260812 06:19:43.589012  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.022s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6635,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:43.589509  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8): perf score=2.188937
I20260812 06:19:43.604705  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.015s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6191,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:43.605213  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling MajorDeltaCompactionOp(54917fe44c344fb0a27cc5ce138586d8): perf score=1.000000
I20260812 06:19:43.794482  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: MajorDeltaCompactionOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.189s	user 0.131s	sys 0.051s Metrics: {"cfile_cache_miss":523,"cfile_cache_miss_bytes":24364567,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":666,"lbm_read_time_us":15518,"lbm_reads_lt_1ms":559,"lbm_write_time_us":35352,"lbm_writes_lt_1ms":533,"peak_mem_usage":61665166,"reinsert_count":0,"spinlock_wait_cycles":13824,"thread_start_us":481,"threads_started":5,"update_count":2450}
I20260812 06:19:43.795185  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8): perf score=10.126437
I20260812 06:19:43.850617  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.055s	user 0.024s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":19389,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:43.851207  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8): perf score=2.188937
I20260812 06:19:43.866947  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.016s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6166,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:43.867496  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling MajorDeltaCompactionOp(54917fe44c344fb0a27cc5ce138586d8): perf score=1.000000
I20260812 06:19:44.036029  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: MajorDeltaCompactionOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.168s	user 0.108s	sys 0.060s 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":510,"lbm_read_time_us":12572,"lbm_reads_lt_1ms":472,"lbm_write_time_us":31196,"lbm_writes_lt_1ms":443,"mutex_wait_us":29,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11264,"update_count":2000}
I20260812 06:19:44.036542  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8): perf score=14.095187
I20260812 06:19:44.107228  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.068s	user 0.050s	sys 0.005s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":23537,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:44.107743  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8): perf score=2.188937
I20260812 06:19:44.124385  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.016s	user 0.009s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6344,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:44.124861  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling MajorDeltaCompactionOp(54917fe44c344fb0a27cc5ce138586d8): perf score=1.000000
I20260812 06:19:44.327422  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: MajorDeltaCompactionOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.202s	user 0.127s	sys 0.069s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1486,"dirs.run_cpu_time_us":1226,"dirs.run_wall_time_us":7782,"lbm_read_time_us":16197,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33008,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6400,"update_count":2500}
I20260812 06:19:44.328231  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8): perf score=10.126437
I20260812 06:19:44.379889  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.050s	user 0.021s	sys 0.027s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":20418,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:44.380517  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8): perf score=2.188937
I20260812 06:19:44.399282  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.019s	user 0.013s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":7113,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:44.399844  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling MajorDeltaCompactionOp(54917fe44c344fb0a27cc5ce138586d8): perf score=1.000000
I20260812 06:19:44.558820  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: MajorDeltaCompactionOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.159s	user 0.098s	sys 0.060s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":831,"lbm_read_time_us":9969,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26433,"lbm_writes_lt_1ms":443,"mutex_wait_us":290,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7936,"thread_start_us":159,"threads_started":2,"update_count":2000}
I20260812 06:19:44.559571  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8): perf score=10.126437
I20260812 06:19:44.613684  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.054s	user 0.032s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20179,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:44.614275  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8): perf score=2.188937
I20260812 06:19:44.625808  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.011s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4609,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:44.626227  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling MajorDeltaCompactionOp(54917fe44c344fb0a27cc5ce138586d8): perf score=1.000000
I20260812 06:19:44.781081  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: MajorDeltaCompactionOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.155s	user 0.119s	sys 0.026s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1116,"lbm_read_time_us":11151,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29706,"lbm_writes_lt_1ms":443,"mutex_wait_us":542,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5632,"update_count":2000}
I20260812 06:19:44.783263  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8): perf score=10.126437
I20260812 06:19:44.834915  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.051s	user 0.033s	sys 0.012s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":26204,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:19:44.835606  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8): perf score=2.188937
I20260812 06:19:44.852675  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.017s	user 0.008s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5828,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:44.853392  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling MajorDeltaCompactionOp(54917fe44c344fb0a27cc5ce138586d8): perf score=1.000000
I20260812 06:19:45.007128  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: MajorDeltaCompactionOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.154s	user 0.129s	sys 0.022s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":363,"lbm_read_time_us":13581,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29603,"lbm_writes_lt_1ms":443,"mutex_wait_us":59,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6016,"update_count":2000}
I20260812 06:19:45.007946  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8): perf score=10.126437
I20260812 06:19:45.069936  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.062s	user 0.027s	sys 0.019s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16747,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:45.070479  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8): perf score=2.188937
I20260812 06:19:45.082522  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.012s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4756,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:45.083061  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling FlushMRSOp(54917fe44c344fb0a27cc5ce138586d8): perf score=1.000000
I20260812 06:19:45.124588  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: FlushMRSOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.041s	user 0.034s	sys 0.005s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":76,"dirs.run_cpu_time_us":262,"dirs.run_wall_time_us":1151,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1837,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:45.125321  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling UndoDeltaBlockGCOp(54917fe44c344fb0a27cc5ce138586d8): 463 bytes on disk
I20260812 06:19:45.125697  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: UndoDeltaBlockGCOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4}
I20260812 06:19:45.126127  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling MajorDeltaCompactionOp(54917fe44c344fb0a27cc5ce138586d8): perf score=1.000000
I20260812 06:19:45.286059  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: MajorDeltaCompactionOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.160s	user 0.109s	sys 0.050s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":594,"lbm_read_time_us":10576,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25711,"lbm_writes_lt_1ms":443,"mutex_wait_us":282,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10240,"update_count":2000}
I20260812 06:19:45.286733  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling LogGCOp(54917fe44c344fb0a27cc5ce138586d8): free 112239311 bytes of WAL
I20260812 06:19:45.287112  9116 log_reader.cc:385] T 54917fe44c344fb0a27cc5ce138586d8: removed 11 log segments from log reader
I20260812 06:19:45.287472  9116 log.cc:1079] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/54917fe44c344fb0a27cc5ce138586d8/wal-000000003 (ops 12-16)
I20260812 06:19:45.287776  9116 log.cc:1079] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/54917fe44c344fb0a27cc5ce138586d8/wal-000000004 (ops 17-21)
I20260812 06:19:45.287904  9116 log.cc:1079] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/54917fe44c344fb0a27cc5ce138586d8/wal-000000005 (ops 22-26)
I20260812 06:19:45.288009  9116 log.cc:1079] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/54917fe44c344fb0a27cc5ce138586d8/wal-000000006 (ops 27-30)
I20260812 06:19:45.288108  9116 log.cc:1079] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/54917fe44c344fb0a27cc5ce138586d8/wal-000000007 (ops 31-35)
I20260812 06:19:45.288198  9116 log.cc:1079] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/54917fe44c344fb0a27cc5ce138586d8/wal-000000008 (ops 36-40)
I20260812 06:19:45.288300  9116 log.cc:1079] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/54917fe44c344fb0a27cc5ce138586d8/wal-000000009 (ops 41-45)
I20260812 06:19:45.288368  9116 log.cc:1079] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/54917fe44c344fb0a27cc5ce138586d8/wal-000000010 (ops 46-50)
I20260812 06:19:45.288431  9116 log.cc:1079] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/54917fe44c344fb0a27cc5ce138586d8/wal-000000011 (ops 51-55)
I20260812 06:19:45.288493  9116 log.cc:1079] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/54917fe44c344fb0a27cc5ce138586d8/wal-000000012 (ops 56-60)
I20260812 06:19:45.288559  9116 log.cc:1079] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/54917fe44c344fb0a27cc5ce138586d8/wal-000000013 (ops 61-65)
I20260812 06:19:45.321024  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: LogGCOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.034s	user 0.002s	sys 0.031s Metrics: {}
I20260812 06:19:45.321606  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8): perf score=12.110812
I20260812 06:19:45.373126  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.051s	user 0.032s	sys 0.015s Metrics: {"bytes_written":14481769,"delete_count":0,"lbm_write_time_us":21960,"lbm_writes_lt_1ms":356,"mutex_wait_us":198,"reinsert_count":0,"update_count":1765}
I20260812 06:19:45.373653  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8): perf score=1.196750
I20260812 06:19:45.389921  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.016s	user 0.003s	sys 0.003s Metrics: {"bytes_written":2338583,"delete_count":0,"lbm_write_time_us":2726,"lbm_writes_lt_1ms":60,"reinsert_count":0,"update_count":285}
I20260812 06:19:45.390441  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8): perf score=2.188937
I20260812 06:19:45.404179  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5585,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:45.404579  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling MajorDeltaCompactionOp(54917fe44c344fb0a27cc5ce138586d8): perf score=1.000000
I20260812 06:19:45.627677  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: MajorDeltaCompactionOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.223s	user 0.152s	sys 0.064s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774757,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":220,"lbm_read_time_us":13663,"lbm_reads_lt_1ms":573,"lbm_write_time_us":38200,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":542,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4096,"update_count":2500}
I20260812 06:19:45.628322  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8): perf score=14.095187
I20260812 06:19:45.691846  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.063s	user 0.038s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":28301,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:45.692444  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8): perf score=2.188937
I20260812 06:19:45.711145  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.019s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5770,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:45.711850  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling MajorDeltaCompactionOp(54917fe44c344fb0a27cc5ce138586d8): perf score=1.000000
I20260812 06:19:45.876272  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: MajorDeltaCompactionOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.164s	user 0.114s	sys 0.047s 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":528,"lbm_read_time_us":11925,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30954,"lbm_writes_lt_1ms":543,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8832,"update_count":2500}
I20260812 06:19:45.876998  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8): perf score=10.126437
I20260812 06:19:45.915179  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.038s	user 0.030s	sys 0.007s Metrics: {"bytes_written":12430565,"delete_count":0,"lbm_write_time_us":16369,"lbm_writes_lt_1ms":306,"reinsert_count":0,"update_count":1515}
I20260812 06:19:45.915733  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8): perf score=2.188937
I20260812 06:19:45.933969  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.018s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3979584,"delete_count":0,"lbm_write_time_us":5555,"lbm_writes_lt_1ms":100,"reinsert_count":0,"update_count":485}
I20260812 06:19:45.934449  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling MajorDeltaCompactionOp(54917fe44c344fb0a27cc5ce138586d8): perf score=1.000000
I20260812 06:19:46.071611  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: MajorDeltaCompactionOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.137s	user 0.126s	sys 0.008s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":265,"lbm_read_time_us":8669,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26115,"lbm_writes_lt_1ms":443,"mutex_wait_us":47,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4992,"update_count":2000}
I20260812 06:19:46.072289  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8): perf score=10.126437
I20260812 06:19:46.126763  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.054s	user 0.025s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19239,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:46.127399  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8): perf score=2.188937
I20260812 06:19:46.142635  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5792,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:46.143241  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling MajorDeltaCompactionOp(54917fe44c344fb0a27cc5ce138586d8): perf score=1.000000
I20260812 06:19:46.299764  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: MajorDeltaCompactionOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.156s	user 0.111s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":536,"lbm_read_time_us":10149,"lbm_reads_lt_1ms":472,"lbm_write_time_us":31775,"lbm_writes_lt_1ms":443,"mutex_wait_us":269,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2000}
I20260812 06:19:46.300381  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8): perf score=10.126437
I20260812 06:19:46.364881  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.064s	user 0.021s	sys 0.035s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17635,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:46.365502  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8): perf score=2.188937
I20260812 06:19:46.381948  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.016s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6132,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:46.382539  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling MajorDeltaCompactionOp(54917fe44c344fb0a27cc5ce138586d8): perf score=1.000000
I20260812 06:19:46.569410  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: MajorDeltaCompactionOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.187s	user 0.134s	sys 0.043s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":949,"lbm_read_time_us":12435,"lbm_reads_lt_1ms":472,"lbm_write_time_us":30427,"lbm_writes_lt_1ms":443,"mutex_wait_us":290,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5760,"update_count":2000}
I20260812 06:19:46.570647  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8): perf score=10.126437
I20260812 06:19:46.610092  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.039s	user 0.022s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16897,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:46.611178  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling MajorDeltaCompactionOp(54917fe44c344fb0a27cc5ce138586d8): perf score=1.000000
I20260812 06:19:46.730500  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: MajorDeltaCompactionOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.119s	user 0.094s	sys 0.025s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569746,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":168,"lbm_read_time_us":7126,"lbm_reads_lt_1ms":363,"lbm_write_time_us":23116,"lbm_writes_lt_1ms":343,"mutex_wait_us":43,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":1500}
I20260812 06:19:46.731122  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8): perf score=10.126437
I20260812 06:19:46.776901  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.046s	user 0.026s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16334,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:46.777417  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8): perf score=2.188937
I20260812 06:19:46.791070  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.013s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4649,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:46.791757  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling FlushMRSOp(54917fe44c344fb0a27cc5ce138586d8): perf score=1.000000
I20260812 06:19:46.829089  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: FlushMRSOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.037s	user 0.035s	sys 0.000s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":69,"dirs.run_cpu_time_us":229,"dirs.run_wall_time_us":1233,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1532,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:46.830394  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling LogGCOp(54917fe44c344fb0a27cc5ce138586d8): free 128867411 bytes of WAL
I20260812 06:19:46.830741  9116 log_reader.cc:385] T 54917fe44c344fb0a27cc5ce138586d8: removed 13 log segments from log reader
I20260812 06:19:46.830883  9116 log.cc:1079] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/54917fe44c344fb0a27cc5ce138586d8/wal-000000014 (ops 66-70)
I20260812 06:19:46.831022  9116 log.cc:1079] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/54917fe44c344fb0a27cc5ce138586d8/wal-000000015 (ops 71-75)
I20260812 06:19:46.831092  9116 log.cc:1079] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/54917fe44c344fb0a27cc5ce138586d8/wal-000000016 (ops 76-80)
I20260812 06:19:46.831173  9116 log.cc:1079] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/54917fe44c344fb0a27cc5ce138586d8/wal-000000017 (ops 81-84)
I20260812 06:19:46.831223  9116 log.cc:1079] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/54917fe44c344fb0a27cc5ce138586d8/wal-000000018 (ops 85-89)
I20260812 06:19:46.831261  9116 log.cc:1079] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/54917fe44c344fb0a27cc5ce138586d8/wal-000000019 (ops 90-94)
I20260812 06:19:46.831308  9116 log.cc:1079] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/54917fe44c344fb0a27cc5ce138586d8/wal-000000020 (ops 95-98)
I20260812 06:19:46.831393  9116 log.cc:1079] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/54917fe44c344fb0a27cc5ce138586d8/wal-000000021 (ops 99-103)
I20260812 06:19:46.831436  9116 log.cc:1079] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/54917fe44c344fb0a27cc5ce138586d8/wal-000000022 (ops 104-108)
I20260812 06:19:46.831506  9116 log.cc:1079] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/54917fe44c344fb0a27cc5ce138586d8/wal-000000023 (ops 109-112)
I20260812 06:19:46.831559  9116 log.cc:1079] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/54917fe44c344fb0a27cc5ce138586d8/wal-000000024 (ops 113-117)
I20260812 06:19:46.831621  9116 log.cc:1079] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/54917fe44c344fb0a27cc5ce138586d8/wal-000000025 (ops 118-122)
I20260812 06:19:46.831670  9116 log.cc:1079] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/54917fe44c344fb0a27cc5ce138586d8/wal-000000026 (ops 123-127)
I20260812 06:19:46.867679  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: LogGCOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.037s	user 0.000s	sys 0.036s Metrics: {}
I20260812 06:19:46.868157  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling UndoDeltaBlockGCOp(54917fe44c344fb0a27cc5ce138586d8): 462 bytes on disk
I20260812 06:19:46.868695  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: UndoDeltaBlockGCOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":89,"lbm_reads_lt_1ms":4}
I20260812 06:19:46.869200  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8): perf score=6.157687
I20260812 06:19:46.918756  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.049s	user 0.027s	sys 0.004s Metrics: {"bytes_written":8205080,"delete_count":0,"lbm_write_time_us":14240,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:46.919296  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8): perf score=2.188937
I20260812 06:19:46.932003  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4665,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:46.932511  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling MajorDeltaCompactionOp(54917fe44c344fb0a27cc5ce138586d8): perf score=1.000000
I20260812 06:19:47.135776  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: MajorDeltaCompactionOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.203s	user 0.144s	sys 0.056s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979754,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":592,"lbm_read_time_us":14767,"lbm_reads_lt_1ms":774,"lbm_write_time_us":44162,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":742,"mutex_wait_us":312,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":3200,"thread_start_us":79,"threads_started":1,"update_count":3500}
I20260812 06:19:47.136287  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8): perf score=14.095187
I20260812 06:19:47.191286  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.055s	user 0.029s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21277,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:47.192037  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8): perf score=2.188937
I20260812 06:19:47.206440  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5580,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:47.207039  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling MajorDeltaCompactionOp(54917fe44c344fb0a27cc5ce138586d8): perf score=1.000000
I20260812 06:19:47.382427  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: MajorDeltaCompactionOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.175s	user 0.125s	sys 0.034s 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":259,"lbm_read_time_us":10399,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34909,"lbm_writes_lt_1ms":543,"mutex_wait_us":33,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8064,"update_count":2500}
I20260812 06:19:47.383173  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8): perf score=14.095187
I20260812 06:19:47.447551  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.064s	user 0.039s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25039,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:47.448196  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8): perf score=2.188937
I20260812 06:19:47.460718  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.012s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4264,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:47.461243  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling MajorDeltaCompactionOp(54917fe44c344fb0a27cc5ce138586d8): perf score=1.000000
I20260812 06:19:47.646728  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: MajorDeltaCompactionOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.185s	user 0.122s	sys 0.059s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1242,"lbm_read_time_us":12268,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30092,"lbm_writes_lt_1ms":543,"mutex_wait_us":594,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3712,"update_count":2500}
I20260812 06:19:47.647490  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8): perf score=14.095187
I20260812 06:19:47.704131  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.056s	user 0.035s	sys 0.019s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25377,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:47.704674  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling MajorDeltaCompactionOp(54917fe44c344fb0a27cc5ce138586d8): perf score=1.000000
I20260812 06:19:47.858362  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: MajorDeltaCompactionOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.154s	user 0.085s	sys 0.068s 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":142,"lbm_read_time_us":12084,"lbm_reads_lt_1ms":463,"lbm_write_time_us":25922,"lbm_writes_lt_1ms":443,"mutex_wait_us":52,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8448,"update_count":2000}
I20260812 06:19:47.859333  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8): perf score=14.095187
I20260812 06:19:47.911733  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.052s	user 0.031s	sys 0.020s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23424,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:47.912590  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8): perf score=2.188937
I20260812 06:19:47.926739  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5613,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:47.927435  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling MajorDeltaCompactionOp(54917fe44c344fb0a27cc5ce138586d8): perf score=1.000000
I20260812 06:19:48.112322  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: MajorDeltaCompactionOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.185s	user 0.114s	sys 0.065s 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":834,"lbm_read_time_us":10636,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31359,"lbm_writes_lt_1ms":543,"mutex_wait_us":363,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4096,"update_count":2500}
I20260812 06:19:48.113164  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8): perf score=14.095187
I20260812 06:19:48.168159  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.055s	user 0.034s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24647,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:48.168684  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8): perf score=2.188937
I20260812 06:19:48.185814  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.017s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6514,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:48.186455  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling MajorDeltaCompactionOp(54917fe44c344fb0a27cc5ce138586d8): perf score=1.000000
I20260812 06:19:48.350071  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: MajorDeltaCompactionOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.163s	user 0.113s	sys 0.043s 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":834,"lbm_read_time_us":10945,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29732,"lbm_writes_lt_1ms":543,"mutex_wait_us":304,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2500}
I20260812 06:19:48.350772  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8): perf score=14.095187
I20260812 06:19:48.407641  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.057s	user 0.024s	sys 0.031s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25946,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:48.408186  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8): perf score=2.188937
I20260812 06:19:48.421844  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5446,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:48.422451  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling FlushMRSOp(54917fe44c344fb0a27cc5ce138586d8): perf score=1.000000
I20260812 06:19:48.457845  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: FlushMRSOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.035s	user 0.033s	sys 0.000s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":78,"dirs.run_cpu_time_us":190,"dirs.run_wall_time_us":1414,"drs_written":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1842,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:19:48.458593  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling LogGCOp(54917fe44c344fb0a27cc5ce138586d8): free 133024640 bytes of WAL
I20260812 06:19:48.458820  9116 log_reader.cc:385] T 54917fe44c344fb0a27cc5ce138586d8: removed 13 log segments from log reader
I20260812 06:19:48.458863  9116 log.cc:1079] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/54917fe44c344fb0a27cc5ce138586d8/wal-000000027 (ops 128-132)
I20260812 06:19:48.458914  9116 log.cc:1079] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/54917fe44c344fb0a27cc5ce138586d8/wal-000000028 (ops 133-137)
I20260812 06:19:48.458978  9116 log.cc:1079] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/54917fe44c344fb0a27cc5ce138586d8/wal-000000029 (ops 138-142)
I20260812 06:19:48.459025  9116 log.cc:1079] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/54917fe44c344fb0a27cc5ce138586d8/wal-000000030 (ops 143-147)
I20260812 06:19:48.459084  9116 log.cc:1079] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/54917fe44c344fb0a27cc5ce138586d8/wal-000000031 (ops 148-152)
I20260812 06:19:48.459125  9116 log.cc:1079] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/54917fe44c344fb0a27cc5ce138586d8/wal-000000032 (ops 153-157)
I20260812 06:19:48.459167  9116 log.cc:1079] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/54917fe44c344fb0a27cc5ce138586d8/wal-000000033 (ops 158-162)
I20260812 06:19:48.459206  9116 log.cc:1079] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/54917fe44c344fb0a27cc5ce138586d8/wal-000000034 (ops 163-167)
I20260812 06:19:48.459245  9116 log.cc:1079] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/54917fe44c344fb0a27cc5ce138586d8/wal-000000035 (ops 168-172)
I20260812 06:19:48.459290  9116 log.cc:1079] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/54917fe44c344fb0a27cc5ce138586d8/wal-000000036 (ops 173-177)
I20260812 06:19:48.459331  9116 log.cc:1079] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/54917fe44c344fb0a27cc5ce138586d8/wal-000000037 (ops 178-182)
I20260812 06:19:48.459371  9116 log.cc:1079] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/54917fe44c344fb0a27cc5ce138586d8/wal-000000038 (ops 183-186)
I20260812 06:19:48.459411  9116 log.cc:1079] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb: Deleting log segment in path: /tmp/dist-test-taskCdkSeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515576990687-8682-0/minicluster-data/ts-0-root/wals/54917fe44c344fb0a27cc5ce138586d8/wal-000000039 (ops 187-191)
I20260812 06:19:48.489348  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: LogGCOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.031s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:19:48.489748  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8): perf score=6.157687
I20260812 06:19:48.522358  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.032s	user 0.015s	sys 0.008s Metrics: {"bytes_written":8205077,"delete_count":0,"lbm_write_time_us":10824,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:48.523001  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling MajorDeltaCompactionOp(54917fe44c344fb0a27cc5ce138586d8): perf score=1.000000
I20260812 06:19:48.721534  8682 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.462s	user 1.962s	sys 0.183s
I20260812 06:19:48.768936  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: MajorDeltaCompactionOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.246s	user 0.151s	sys 0.093s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32979632,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"lbm_read_time_us":17859,"lbm_reads_lt_1ms":761,"lbm_write_time_us":41280,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":3500}
I20260812 06:19:48.769820  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8): perf score=14.095187
I20260812 06:19:48.820502  8682 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.099s	user 0.007s	sys 0.001s
I20260812 06:19:48.821152  8682 tablet_server.cc:179] TabletServer@127.8.122.129:0 shutting down...
I20260812 06:19:48.821537  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: FlushDeltaMemStoresOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.052s	user 0.030s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17132,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:48.822242  9200 maintenance_manager.cc:419] P d1e974c921d54afbb277e96a7d9f21cb: Scheduling MajorDeltaCompactionOp(54917fe44c344fb0a27cc5ce138586d8): perf score=1.000000
I20260812 06:19:48.962126  9116 maintenance_manager.cc:643] P d1e974c921d54afbb277e96a7d9f21cb: MajorDeltaCompactionOp(54917fe44c344fb0a27cc5ce138586d8) complete. Timing: real 0.140s	user 0.110s	sys 0.027s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":430,"lbm_read_time_us":9623,"lbm_reads_lt_1ms":467,"lbm_write_time_us":22680,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:48.963126  8682 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:48.963340  8682 tablet_replica.cc:333] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb: stopping tablet replica
I20260812 06:19:48.963441  8682 raft_consensus.cc:2243] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:48.963611  8682 raft_consensus.cc:2272] T 54917fe44c344fb0a27cc5ce138586d8 P d1e974c921d54afbb277e96a7d9f21cb [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:48.978700  8682 tablet_server.cc:196] TabletServer@127.8.122.129:0 shutdown complete.
I20260812 06:19:49.001708  8682 master.cc:562] Master@127.8.122.190:33655 shutting down...
I20260812 06:19:49.005735  8682 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 747a3fe2b0c74a2bb2117315f4291c60 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:49.005949  8682 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 747a3fe2b0c74a2bb2117315f4291c60 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:49.005999  8682 tablet_replica.cc:333] T 00000000000000000000000000000000 P 747a3fe2b0c74a2bb2117315f4291c60: stopping tablet replica
I20260812 06:19:49.018657  8682 master.cc:584] Master@127.8.122.190:33655 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (6092 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (12116 ms total)

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