[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:18:53.916092  2905 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.2.214.126:41191
I20260812 06:18:53.916990  2905 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:18:53.917554  2905 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:53.923024  2915 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:53.923062  2920 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:53.923036  2924 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:53.923360  2905 server_base.cc:1061] running on GCE node
I20260812 06:18:53.923749  2905 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:53.923841  2905 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:53.923872  2905 hybrid_clock.cc:648] HybridClock initialized: now 1786515533923870 us; error 0 us; skew 500 ppm
I20260812 06:18:53.927588  2905 webserver.cc:533] Webserver started at http://127.2.214.126:37223/ using document root <none> and password file <none>
I20260812 06:18:53.928048  2905 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:53.928097  2905 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:53.928277  2905 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:53.929703  2905 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533906135-2905-0/minicluster-data/master-0-root/instance:
uuid: "5f611ddc6b204762a69d180fa19caf68"
format_stamp: "Formatted at 2026-08-12 06:18:53 on dist-test-slave-tc2s"
I20260812 06:18:53.932803  2905 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:18:53.934607  2934 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:53.935492  2905 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:53.935588  2905 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533906135-2905-0/minicluster-data/master-0-root
uuid: "5f611ddc6b204762a69d180fa19caf68"
format_stamp: "Formatted at 2026-08-12 06:18:53 on dist-test-slave-tc2s"
I20260812 06:18:53.935658  2905 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533906135-2905-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533906135-2905-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533906135-2905-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:53.950186  2905 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:53.950656  2905 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:18:53.950768  2905 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:53.957343  3020 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.2.214.126:41191 every 8 connection(s)
I20260812 06:18:53.957346  2905 rpc_server.cc:307] RPC server started. Bound to: 127.2.214.126:41191
I20260812 06:18:53.959481  3021 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:53.964572  3021 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 5f611ddc6b204762a69d180fa19caf68: Bootstrap starting.
I20260812 06:18:53.966805  3021 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 5f611ddc6b204762a69d180fa19caf68: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:53.967624  3021 log.cc:826] T 00000000000000000000000000000000 P 5f611ddc6b204762a69d180fa19caf68: Log is configured to *not* fsync() on all Append() calls
I20260812 06:18:53.969115  3021 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 5f611ddc6b204762a69d180fa19caf68: No bootstrap required, opened a new log
I20260812 06:18:53.971719  3021 raft_consensus.cc:359] T 00000000000000000000000000000000 P 5f611ddc6b204762a69d180fa19caf68 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5f611ddc6b204762a69d180fa19caf68" member_type: VOTER }
I20260812 06:18:53.971868  3021 raft_consensus.cc:385] T 00000000000000000000000000000000 P 5f611ddc6b204762a69d180fa19caf68 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:53.971941  3021 raft_consensus.cc:740] T 00000000000000000000000000000000 P 5f611ddc6b204762a69d180fa19caf68 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 5f611ddc6b204762a69d180fa19caf68, State: Initialized, Role: FOLLOWER
I20260812 06:18:53.972517  3021 consensus_queue.cc:260] T 00000000000000000000000000000000 P 5f611ddc6b204762a69d180fa19caf68 [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: "5f611ddc6b204762a69d180fa19caf68" member_type: VOTER }
I20260812 06:18:53.972666  3021 raft_consensus.cc:399] T 00000000000000000000000000000000 P 5f611ddc6b204762a69d180fa19caf68 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:53.972730  3021 raft_consensus.cc:493] T 00000000000000000000000000000000 P 5f611ddc6b204762a69d180fa19caf68 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:53.972846  3021 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 5f611ddc6b204762a69d180fa19caf68 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:53.973531  3021 raft_consensus.cc:515] T 00000000000000000000000000000000 P 5f611ddc6b204762a69d180fa19caf68 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5f611ddc6b204762a69d180fa19caf68" member_type: VOTER }
I20260812 06:18:53.973949  3021 leader_election.cc:304] T 00000000000000000000000000000000 P 5f611ddc6b204762a69d180fa19caf68 [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: 5f611ddc6b204762a69d180fa19caf68; no voters: 
I20260812 06:18:53.974216  3021 leader_election.cc:290] T 00000000000000000000000000000000 P 5f611ddc6b204762a69d180fa19caf68 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:53.974309  3024 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 5f611ddc6b204762a69d180fa19caf68 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:53.974504  3024 raft_consensus.cc:697] T 00000000000000000000000000000000 P 5f611ddc6b204762a69d180fa19caf68 [term 1 LEADER]: Becoming Leader. State: Replica: 5f611ddc6b204762a69d180fa19caf68, State: Running, Role: LEADER
I20260812 06:18:53.974903  3024 consensus_queue.cc:237] T 00000000000000000000000000000000 P 5f611ddc6b204762a69d180fa19caf68 [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: "5f611ddc6b204762a69d180fa19caf68" member_type: VOTER }
I20260812 06:18:53.975126  3021 sys_catalog.cc:565] T 00000000000000000000000000000000 P 5f611ddc6b204762a69d180fa19caf68 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:53.976606  3025 sys_catalog.cc:455] T 00000000000000000000000000000000 P 5f611ddc6b204762a69d180fa19caf68 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "5f611ddc6b204762a69d180fa19caf68" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5f611ddc6b204762a69d180fa19caf68" member_type: VOTER } }
I20260812 06:18:53.976573  3026 sys_catalog.cc:455] T 00000000000000000000000000000000 P 5f611ddc6b204762a69d180fa19caf68 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 5f611ddc6b204762a69d180fa19caf68. Latest consensus state: current_term: 1 leader_uuid: "5f611ddc6b204762a69d180fa19caf68" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5f611ddc6b204762a69d180fa19caf68" member_type: VOTER } }
I20260812 06:18:53.976702  3025 sys_catalog.cc:458] T 00000000000000000000000000000000 P 5f611ddc6b204762a69d180fa19caf68 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:53.976702  3026 sys_catalog.cc:458] T 00000000000000000000000000000000 P 5f611ddc6b204762a69d180fa19caf68 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:53.977124  3039 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:53.977347  2905 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:53.979409  3039 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:53.983544  3039 catalog_manager.cc:1383] Generated new cluster ID: fc056b3cec4d4feb8ae48b5eb2be5044
I20260812 06:18:53.983594  3039 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:53.991027  3039 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:53.991717  3039 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:53.996732  3039 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 5f611ddc6b204762a69d180fa19caf68: Generated new TSK 0
I20260812 06:18:53.997202  3039 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:54.010162  2905 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:54.012820  3058 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:54.012827  3057 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:54.012987  3061 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:54.013108  2905 server_base.cc:1061] running on GCE node
I20260812 06:18:54.013259  2905 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:54.013298  2905 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:54.013311  2905 hybrid_clock.cc:648] HybridClock initialized: now 1786515534013311 us; error 0 us; skew 500 ppm
I20260812 06:18:54.014176  2905 webserver.cc:533] Webserver started at http://127.2.214.65:38197/ using document root <none> and password file <none>
I20260812 06:18:54.014330  2905 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:54.014379  2905 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:54.014460  2905 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:54.014798  2905 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533906135-2905-0/minicluster-data/ts-0-root/instance:
uuid: "4ae6a3b0f7024ae396ab1d70bebaa5ea"
format_stamp: "Formatted at 2026-08-12 06:18:54 on dist-test-slave-tc2s"
I20260812 06:18:54.016183  2905 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:54.017092  3068 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:54.017297  2905 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:54.017364  2905 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533906135-2905-0/minicluster-data/ts-0-root
uuid: "4ae6a3b0f7024ae396ab1d70bebaa5ea"
format_stamp: "Formatted at 2026-08-12 06:18:54 on dist-test-slave-tc2s"
I20260812 06:18:54.017436  2905 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533906135-2905-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533906135-2905-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533906135-2905-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:54.045478  2905 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:54.045886  2905 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:54.046347  2905 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:54.047170  2905 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:54.047222  2905 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:54.047266  2905 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:54.047297  2905 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:54.053285  2905 rpc_server.cc:307] RPC server started. Bound to: 127.2.214.65:43697
I20260812 06:18:54.053328  3190 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.2.214.65:43697 every 8 connection(s)
I20260812 06:18:54.066175  3191 heartbeater.cc:344] Connected to a master server at 127.2.214.126:41191
I20260812 06:18:54.066394  3191 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:54.066794  3191 heartbeater.cc:507] Master 127.2.214.126:41191 requested a full tablet report, sending...
I20260812 06:18:54.068102  2970 ts_manager.cc:194] Registered new tserver with Master: 4ae6a3b0f7024ae396ab1d70bebaa5ea (127.2.214.65:43697)
I20260812 06:18:54.068203  2905 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.014349103s
I20260812 06:18:54.069226  2970 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:48588
I20260812 06:18:54.076691  2970 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:48602:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:18:54.090984  3127 tablet_service.cc:1511] Processing CreateTablet for tablet 164961225ffc4646a661951030d663c6 (DEFAULT_TABLE table=heavy-update-compaction-test [id=3bcc7e9df89c4fff92fe28331c29e360]), partition=
I20260812 06:18:54.091461  3127 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 164961225ffc4646a661951030d663c6. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:54.098129  3206 tablet_bootstrap.cc:492] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Bootstrap starting.
I20260812 06:18:54.099839  3206 tablet_bootstrap.cc:654] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:54.102721  3206 tablet_bootstrap.cc:492] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea: No bootstrap required, opened a new log
I20260812 06:18:54.102842  3206 ts_tablet_manager.cc:1403] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Time spent bootstrapping tablet: real 0.005s	user 0.004s	sys 0.000s
I20260812 06:18:54.103401  3206 raft_consensus.cc:359] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4ae6a3b0f7024ae396ab1d70bebaa5ea" member_type: VOTER last_known_addr { host: "127.2.214.65" port: 43697 } }
I20260812 06:18:54.103519  3206 raft_consensus.cc:385] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:54.103545  3206 raft_consensus.cc:740] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 4ae6a3b0f7024ae396ab1d70bebaa5ea, State: Initialized, Role: FOLLOWER
I20260812 06:18:54.103686  3206 consensus_queue.cc:260] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea [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: "4ae6a3b0f7024ae396ab1d70bebaa5ea" member_type: VOTER last_known_addr { host: "127.2.214.65" port: 43697 } }
I20260812 06:18:54.103786  3206 raft_consensus.cc:399] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:54.103829  3206 raft_consensus.cc:493] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:54.103881  3206 raft_consensus.cc:3060] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:54.104733  3206 raft_consensus.cc:515] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4ae6a3b0f7024ae396ab1d70bebaa5ea" member_type: VOTER last_known_addr { host: "127.2.214.65" port: 43697 } }
I20260812 06:18:54.104889  3206 leader_election.cc:304] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea [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: 4ae6a3b0f7024ae396ab1d70bebaa5ea; no voters: 
I20260812 06:18:54.105093  3206 leader_election.cc:290] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:54.105252  3211 raft_consensus.cc:2804] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:54.105480  3206 ts_tablet_manager.cc:1434] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:18:54.105587  3211 raft_consensus.cc:697] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea [term 1 LEADER]: Becoming Leader. State: Replica: 4ae6a3b0f7024ae396ab1d70bebaa5ea, State: Running, Role: LEADER
I20260812 06:18:54.105782  3211 consensus_queue.cc:237] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea [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: "4ae6a3b0f7024ae396ab1d70bebaa5ea" member_type: VOTER last_known_addr { host: "127.2.214.65" port: 43697 } }
I20260812 06:18:54.105921  3191 heartbeater.cc:499] Master 127.2.214.126:41191 was elected leader, sending a full tablet report...
I20260812 06:18:54.109752  2970 catalog_manager.cc:5719] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea reported cstate change: term changed from 0 to 1, leader changed from <none> to 4ae6a3b0f7024ae396ab1d70bebaa5ea (127.2.214.65). New cstate: current_term: 1 leader_uuid: "4ae6a3b0f7024ae396ab1d70bebaa5ea" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4ae6a3b0f7024ae396ab1d70bebaa5ea" member_type: VOTER last_known_addr { host: "127.2.214.65" port: 43697 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:54.178110  2905 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.063s	user 0.024s	sys 0.007s
I20260812 06:18:54.304296  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling FlushMRSOp(164961225ffc4646a661951030d663c6): perf score=19.054940
I20260812 06:18:54.457526  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: FlushMRSOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.153s	user 0.125s	sys 0.024s Metrics: {"bytes_written":9148638,"cfile_init":1,"compiler_manager_pool.queue_time_us":184,"delete_count":0,"dirs.queue_time_us":60,"dirs.run_cpu_time_us":195,"dirs.run_wall_time_us":767,"drs_written":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4,"lbm_write_time_us":38198,"lbm_writes_lt_1ms":680,"mutex_wait_us":129,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":260864,"thread_start_us":103,"threads_started":1,"update_count":1115}
I20260812 06:18:54.458863  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling LogGCOp(164961225ffc4646a661951030d663c6): free 20743880 bytes of WAL
I20260812 06:18:54.459429  3081 log_reader.cc:385] T 164961225ffc4646a661951030d663c6: removed 2 log segments from log reader
I20260812 06:18:54.459637  3081 log.cc:1079] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/164961225ffc4646a661951030d663c6/wal-000000001 (ops 1-6)
I20260812 06:18:54.459837  3081 log.cc:1079] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/164961225ffc4646a661951030d663c6/wal-000000002 (ops 7-11)
I20260812 06:18:54.464872  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: LogGCOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.006s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:18:54.465206  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6): perf score=2.188937
I20260812 06:18:54.487934  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.023s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3569334,"delete_count":0,"lbm_write_time_us":5053,"lbm_writes_lt_1ms":90,"reinsert_count":0,"update_count":435}
I20260812 06:18:54.488317  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling UndoDeltaBlockGCOp(164961225ffc4646a661951030d663c6): 16411392 bytes on disk
I20260812 06:18:54.488801  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: UndoDeltaBlockGCOp(164961225ffc4646a661951030d663c6) 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:18:54.489221  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6): perf score=2.188937
I20260812 06:18:54.498327  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.009s	user 0.001s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3384,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:54.498786  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling MajorDeltaCompactionOp(164961225ffc4646a661951030d663c6): perf score=1.000000
I20260812 06:18:54.626796  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: MajorDeltaCompactionOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.128s	user 0.089s	sys 0.037s Metrics: {"cfile_cache_miss":433,"cfile_cache_miss_bytes":20672377,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":782,"lbm_read_time_us":8644,"lbm_reads_lt_1ms":469,"lbm_write_time_us":22246,"lbm_writes_lt_1ms":443,"mutex_wait_us":118,"peak_mem_usage":50689328,"reinsert_count":0,"thread_start_us":289,"threads_started":5,"update_count":2000}
I20260812 06:18:54.627236  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6): perf score=10.126437
I20260812 06:18:54.669016  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.042s	user 0.013s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13691,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:54.669468  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6): perf score=2.188937
I20260812 06:18:54.679649  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3836,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:54.680169  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling MajorDeltaCompactionOp(164961225ffc4646a661951030d663c6): perf score=1.000000
I20260812 06:18:54.798978  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: MajorDeltaCompactionOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.119s	user 0.099s	sys 0.019s 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":761,"lbm_read_time_us":8571,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21546,"lbm_writes_lt_1ms":443,"mutex_wait_us":263,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":89856,"update_count":2000}
I20260812 06:18:54.799415  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6): perf score=10.126437
I20260812 06:18:54.836615  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.037s	user 0.017s	sys 0.012s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":13338,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:54.837170  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6): perf score=2.188937
I20260812 06:18:54.851375  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.014s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5645,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:54.851857  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling MajorDeltaCompactionOp(164961225ffc4646a661951030d663c6): perf score=1.000000
I20260812 06:18:54.972059  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: MajorDeltaCompactionOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.120s	user 0.097s	sys 0.022s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":567,"lbm_read_time_us":8106,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23605,"lbm_writes_lt_1ms":443,"mutex_wait_us":41,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2000}
I20260812 06:18:54.972529  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6): perf score=10.126437
I20260812 06:18:55.014469  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.042s	user 0.017s	sys 0.025s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":13132,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:55.015059  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6): perf score=2.188937
I20260812 06:18:55.030256  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.015s	user 0.002s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5918,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:55.030694  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling MajorDeltaCompactionOp(164961225ffc4646a661951030d663c6): perf score=1.000000
I20260812 06:18:55.164130  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: MajorDeltaCompactionOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.133s	user 0.097s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":570,"lbm_read_time_us":10192,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21312,"lbm_writes_lt_1ms":443,"mutex_wait_us":251,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":2000}
I20260812 06:18:55.164568  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6): perf score=10.126437
I20260812 06:18:55.208190  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.043s	user 0.026s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17909,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:55.208652  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6): perf score=2.188937
I20260812 06:18:55.218461  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3763,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:55.218927  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling MajorDeltaCompactionOp(164961225ffc4646a661951030d663c6): perf score=1.000000
I20260812 06:18:55.339699  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: MajorDeltaCompactionOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.121s	user 0.090s	sys 0.030s 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":143,"lbm_read_time_us":9833,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22353,"lbm_writes_lt_1ms":443,"mutex_wait_us":30,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2000}
I20260812 06:18:55.340337  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6): perf score=10.126437
I20260812 06:18:55.377197  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.037s	user 0.011s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13461,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:55.377671  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6): perf score=2.188937
I20260812 06:18:55.387621  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.010s	user 0.005s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3829,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:55.388036  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling MajorDeltaCompactionOp(164961225ffc4646a661951030d663c6): perf score=1.000000
I20260812 06:18:55.510304  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: MajorDeltaCompactionOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.122s	user 0.097s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1115,"lbm_read_time_us":8946,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23285,"lbm_writes_lt_1ms":443,"mutex_wait_us":382,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":17920,"update_count":2000}
I20260812 06:18:55.510847  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6): perf score=10.126437
I20260812 06:18:55.556423  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.045s	user 0.011s	sys 0.032s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":17354,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:55.556937  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6): perf score=2.188937
I20260812 06:18:55.571981  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.015s	user 0.000s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5884,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:55.572487  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling FlushMRSOp(164961225ffc4646a661951030d663c6): perf score=1.000000
I20260812 06:18:55.612162  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: FlushMRSOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.039s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":55,"dirs.run_cpu_time_us":204,"dirs.run_wall_time_us":1214,"drs_written":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1434,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:55.613099  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling LogGCOp(164961225ffc4646a661951030d663c6): free 111786259 bytes of WAL
I20260812 06:18:55.613332  3081 log_reader.cc:385] T 164961225ffc4646a661951030d663c6: removed 11 log segments from log reader
I20260812 06:18:55.613384  3081 log.cc:1079] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/164961225ffc4646a661951030d663c6/wal-000000003 (ops 12-16)
I20260812 06:18:55.613420  3081 log.cc:1079] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/164961225ffc4646a661951030d663c6/wal-000000004 (ops 17-20)
I20260812 06:18:55.613452  3081 log.cc:1079] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/164961225ffc4646a661951030d663c6/wal-000000005 (ops 21-25)
I20260812 06:18:55.613483  3081 log.cc:1079] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/164961225ffc4646a661951030d663c6/wal-000000006 (ops 26-30)
I20260812 06:18:55.613516  3081 log.cc:1079] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/164961225ffc4646a661951030d663c6/wal-000000007 (ops 31-35)
I20260812 06:18:55.613546  3081 log.cc:1079] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/164961225ffc4646a661951030d663c6/wal-000000008 (ops 36-40)
I20260812 06:18:55.613576  3081 log.cc:1079] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/164961225ffc4646a661951030d663c6/wal-000000009 (ops 41-45)
I20260812 06:18:55.613606  3081 log.cc:1079] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/164961225ffc4646a661951030d663c6/wal-000000010 (ops 46-50)
I20260812 06:18:55.613636  3081 log.cc:1079] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/164961225ffc4646a661951030d663c6/wal-000000011 (ops 51-54)
I20260812 06:18:55.613665  3081 log.cc:1079] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/164961225ffc4646a661951030d663c6/wal-000000012 (ops 55-59)
I20260812 06:18:55.613694  3081 log.cc:1079] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/164961225ffc4646a661951030d663c6/wal-000000013 (ops 60-64)
I20260812 06:18:55.632006  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: LogGCOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.019s	user 0.000s	sys 0.017s Metrics: {}
I20260812 06:18:55.632413  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling UndoDeltaBlockGCOp(164961225ffc4646a661951030d663c6): 447 bytes on disk
I20260812 06:18:55.632843  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: UndoDeltaBlockGCOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:18:55.633347  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6): perf score=3.181125
I20260812 06:18:55.655584  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.022s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4334,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:55.655982  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6): perf score=2.188937
I20260812 06:18:55.668430  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4817,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:55.668911  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling MajorDeltaCompactionOp(164961225ffc4646a661951030d663c6): perf score=1.000000
I20260812 06:18:55.862123  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: MajorDeltaCompactionOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.193s	user 0.136s	sys 0.052s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877331,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":515,"lbm_read_time_us":12298,"lbm_reads_lt_1ms":674,"lbm_write_time_us":31218,"lbm_writes_lt_1ms":643,"mutex_wait_us":675,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":384,"thread_start_us":73,"threads_started":1,"update_count":3000}
I20260812 06:18:55.862663  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6): perf score=14.095187
I20260812 06:18:55.916154  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.053s	user 0.024s	sys 0.026s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24069,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:55.916653  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling MajorDeltaCompactionOp(164961225ffc4646a661951030d663c6): perf score=1.000000
I20260812 06:18:56.058151  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: MajorDeltaCompactionOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.141s	user 0.085s	sys 0.045s 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":511,"lbm_read_time_us":10521,"lbm_reads_lt_1ms":463,"lbm_write_time_us":20585,"lbm_writes_lt_1ms":443,"mutex_wait_us":299,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12544,"update_count":2000}
I20260812 06:18:56.058709  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6): perf score=14.095187
I20260812 06:18:56.105168  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.046s	user 0.024s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":16969,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:56.105620  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6): perf score=2.188937
I20260812 06:18:56.120718  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.015s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5938,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:56.121246  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling MajorDeltaCompactionOp(164961225ffc4646a661951030d663c6): perf score=1.000000
I20260812 06:18:56.306003  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: MajorDeltaCompactionOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.185s	user 0.122s	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":251,"lbm_read_time_us":10379,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28015,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":587520,"update_count":2500}
I20260812 06:18:56.306484  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6): perf score=14.095187
I20260812 06:18:56.356906  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.050s	user 0.021s	sys 0.022s Metrics: {"bytes_written":16409918,"delete_count":0,"lbm_write_time_us":20236,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:56.357447  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6): perf score=2.188937
I20260812 06:18:56.374796  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.017s	user 0.007s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":8264,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":102,"reinsert_count":0,"update_count":500}
I20260812 06:18:56.375418  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling MajorDeltaCompactionOp(164961225ffc4646a661951030d663c6): perf score=1.000000
I20260812 06:18:56.524803  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: MajorDeltaCompactionOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.149s	user 0.117s	sys 0.026s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774705,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":102,"lbm_read_time_us":11430,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25928,"lbm_writes_lt_1ms":543,"mutex_wait_us":35,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10240,"update_count":2500}
I20260812 06:18:56.525287  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6): perf score=10.126437
I20260812 06:18:56.561533  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.036s	user 0.019s	sys 0.008s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":13495,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:56.562153  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling MajorDeltaCompactionOp(164961225ffc4646a661951030d663c6): perf score=1.000000
I20260812 06:18:56.679190  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: MajorDeltaCompactionOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.117s	user 0.077s	sys 0.035s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569748,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":968,"lbm_read_time_us":7473,"lbm_reads_lt_1ms":363,"lbm_write_time_us":19408,"lbm_writes_lt_1ms":343,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":3072,"update_count":1500}
I20260812 06:18:56.679629  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6): perf score=10.126437
I20260812 06:18:56.708068  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.028s	user 0.017s	sys 0.009s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":11910,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:56.708551  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling MajorDeltaCompactionOp(164961225ffc4646a661951030d663c6): perf score=1.000000
I20260812 06:18:56.817680  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: MajorDeltaCompactionOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.109s	user 0.081s	sys 0.024s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569746,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":558,"lbm_read_time_us":6326,"lbm_reads_lt_1ms":367,"lbm_write_time_us":18631,"lbm_writes_lt_1ms":343,"mutex_wait_us":49,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":4992,"update_count":1500}
I20260812 06:18:56.818222  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6): perf score=10.126437
I20260812 06:18:56.863322  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.045s	user 0.024s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15998,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":1500}
I20260812 06:18:56.863795  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6): perf score=2.188937
I20260812 06:18:56.873224  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3573,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:56.873639  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling MajorDeltaCompactionOp(164961225ffc4646a661951030d663c6): perf score=1.000000
I20260812 06:18:56.995182  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: MajorDeltaCompactionOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.121s	user 0.100s	sys 0.021s 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":244,"lbm_read_time_us":9184,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22320,"lbm_writes_lt_1ms":443,"mutex_wait_us":46,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:18:56.995712  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6): perf score=10.126437
I20260812 06:18:57.028039  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.032s	user 0.009s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13288,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:57.028484  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6): perf score=2.188937
I20260812 06:18:57.037954  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.009s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3571,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:57.038363  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling FlushMRSOp(164961225ffc4646a661951030d663c6): perf score=1.000000
I20260812 06:18:57.065768  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: FlushMRSOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.027s	user 0.026s	sys 0.000s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":54,"dirs.run_cpu_time_us":203,"dirs.run_wall_time_us":1081,"drs_written":1,"lbm_read_time_us":35,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1302,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:18:57.066463  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling LogGCOp(164961225ffc4646a661951030d663c6): free 121006383 bytes of WAL
I20260812 06:18:57.066679  3081 log_reader.cc:385] T 164961225ffc4646a661951030d663c6: removed 12 log segments from log reader
I20260812 06:18:57.066746  3081 log.cc:1079] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/164961225ffc4646a661951030d663c6/wal-000000014 (ops 65-69)
I20260812 06:18:57.066794  3081 log.cc:1079] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/164961225ffc4646a661951030d663c6/wal-000000015 (ops 70-74)
I20260812 06:18:57.066823  3081 log.cc:1079] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/164961225ffc4646a661951030d663c6/wal-000000016 (ops 75-79)
I20260812 06:18:57.066851  3081 log.cc:1079] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/164961225ffc4646a661951030d663c6/wal-000000017 (ops 80-84)
I20260812 06:18:57.066882  3081 log.cc:1079] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/164961225ffc4646a661951030d663c6/wal-000000018 (ops 85-89)
I20260812 06:18:57.066915  3081 log.cc:1079] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/164961225ffc4646a661951030d663c6/wal-000000019 (ops 90-94)
I20260812 06:18:57.066946  3081 log.cc:1079] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/164961225ffc4646a661951030d663c6/wal-000000020 (ops 95-99)
I20260812 06:18:57.066973  3081 log.cc:1079] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/164961225ffc4646a661951030d663c6/wal-000000021 (ops 100-104)
I20260812 06:18:57.067000  3081 log.cc:1079] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/164961225ffc4646a661951030d663c6/wal-000000022 (ops 105-109)
I20260812 06:18:57.067028  3081 log.cc:1079] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/164961225ffc4646a661951030d663c6/wal-000000023 (ops 110-114)
I20260812 06:18:57.067060  3081 log.cc:1079] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/164961225ffc4646a661951030d663c6/wal-000000024 (ops 115-118)
I20260812 06:18:57.067090  3081 log.cc:1079] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/164961225ffc4646a661951030d663c6/wal-000000025 (ops 119-123)
I20260812 06:18:57.090564  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: LogGCOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.024s	user 0.001s	sys 0.023s Metrics: {}
I20260812 06:18:57.090987  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling UndoDeltaBlockGCOp(164961225ffc4646a661951030d663c6): 472 bytes on disk
I20260812 06:18:57.091404  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: UndoDeltaBlockGCOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4}
I20260812 06:18:57.091962  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6): perf score=2.188937
I20260812 06:18:57.108327  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.016s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4515,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:57.108702  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6): perf score=2.188937
I20260812 06:18:57.118314  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.009s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3684,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:57.118726  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling MajorDeltaCompactionOp(164961225ffc4646a661951030d663c6): perf score=1.000000
I20260812 06:18:57.294165  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: MajorDeltaCompactionOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.175s	user 0.139s	sys 0.027s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877337,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":207,"lbm_read_time_us":11675,"lbm_reads_lt_1ms":674,"lbm_write_time_us":32578,"lbm_writes_lt_1ms":643,"mutex_wait_us":23,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":48512,"thread_start_us":71,"threads_started":1,"update_count":3000}
I20260812 06:18:57.294718  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6): perf score=14.095187
I20260812 06:18:57.339178  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.044s	user 0.030s	sys 0.007s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":16951,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:57.339713  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6): perf score=2.188937
I20260812 06:18:57.349696  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3886,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:57.350348  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling MajorDeltaCompactionOp(164961225ffc4646a661951030d663c6): perf score=1.000000
I20260812 06:18:57.497627  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: MajorDeltaCompactionOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.147s	user 0.096s	sys 0.041s 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":138,"lbm_read_time_us":9241,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28429,"lbm_writes_lt_1ms":543,"mutex_wait_us":62,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1152,"update_count":2500}
I20260812 06:18:57.498231  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6): perf score=14.095187
I20260812 06:18:57.548287  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.050s	user 0.030s	sys 0.016s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23569,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:18:57.548765  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6): perf score=2.188937
I20260812 06:18:57.562537  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.014s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4865,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:57.563161  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling MajorDeltaCompactionOp(164961225ffc4646a661951030d663c6): perf score=1.000000
I20260812 06:18:57.706497  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: MajorDeltaCompactionOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.143s	user 0.105s	sys 0.028s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":233,"lbm_read_time_us":8556,"lbm_reads_lt_1ms":564,"lbm_write_time_us":26844,"lbm_writes_lt_1ms":543,"mutex_wait_us":56,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1152,"update_count":2500}
I20260812 06:18:57.706919  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6): perf score=14.095187
I20260812 06:18:57.768575  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.062s	user 0.024s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21050,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:57.769227  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6): perf score=2.188937
I20260812 06:18:57.784371  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.015s	user 0.009s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5681,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:57.784809  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling MajorDeltaCompactionOp(164961225ffc4646a661951030d663c6): perf score=1.000000
I20260812 06:18:57.946624  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: MajorDeltaCompactionOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.162s	user 0.110s	sys 0.051s 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":581,"lbm_read_time_us":10343,"lbm_reads_lt_1ms":564,"lbm_write_time_us":28468,"lbm_writes_lt_1ms":543,"mutex_wait_us":277,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:57.947172  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6): perf score=14.095187
I20260812 06:18:58.000528  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.053s	user 0.033s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19924,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:58.001009  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6): perf score=2.188937
I20260812 06:18:58.011145  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3900,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:58.011746  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling MajorDeltaCompactionOp(164961225ffc4646a661951030d663c6): perf score=1.000000
I20260812 06:18:58.174772  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: MajorDeltaCompactionOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.163s	user 0.118s	sys 0.039s 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":160,"lbm_read_time_us":11944,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28195,"lbm_writes_lt_1ms":543,"mutex_wait_us":60,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3968,"update_count":2500}
I20260812 06:18:58.175271  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6): perf score=14.095187
I20260812 06:18:58.227764  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.052s	user 0.030s	sys 0.014s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17344,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:58.228240  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6): perf score=2.188937
I20260812 06:18:58.238153  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3867,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:58.238535  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling MajorDeltaCompactionOp(164961225ffc4646a661951030d663c6): perf score=1.000000
I20260812 06:18:58.419068  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: MajorDeltaCompactionOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.180s	user 0.106s	sys 0.062s 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":679,"lbm_read_time_us":11762,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28982,"lbm_writes_lt_1ms":543,"mutex_wait_us":40,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11264,"update_count":2500}
I20260812 06:18:58.419571  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6): perf score=14.095187
I20260812 06:18:58.474241  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.055s	user 0.025s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20396,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:58.474680  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6): perf score=2.188937
I20260812 06:18:58.484683  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3894,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:58.485085  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling FlushMRSOp(164961225ffc4646a661951030d663c6): perf score=1.000000
I20260812 06:18:58.525982  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: FlushMRSOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.041s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":57,"dirs.run_cpu_time_us":183,"dirs.run_wall_time_us":1163,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1512,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:58.526793  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling LogGCOp(164961225ffc4646a661951030d663c6): free 136728545 bytes of WAL
I20260812 06:18:58.527040  3081 log_reader.cc:385] T 164961225ffc4646a661951030d663c6: removed 13 log segments from log reader
I20260812 06:18:58.527091  3081 log.cc:1079] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/164961225ffc4646a661951030d663c6/wal-000000026 (ops 124-128)
I20260812 06:18:58.527127  3081 log.cc:1079] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/164961225ffc4646a661951030d663c6/wal-000000027 (ops 129-133)
I20260812 06:18:58.527160  3081 log.cc:1079] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/164961225ffc4646a661951030d663c6/wal-000000028 (ops 134-138)
I20260812 06:18:58.527192  3081 log.cc:1079] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/164961225ffc4646a661951030d663c6/wal-000000029 (ops 139-143)
I20260812 06:18:58.527223  3081 log.cc:1079] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/164961225ffc4646a661951030d663c6/wal-000000030 (ops 144-148)
I20260812 06:18:58.527254  3081 log.cc:1079] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/164961225ffc4646a661951030d663c6/wal-000000031 (ops 149-153)
I20260812 06:18:58.527284  3081 log.cc:1079] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/164961225ffc4646a661951030d663c6/wal-000000032 (ops 154-158)
I20260812 06:18:58.527311  3081 log.cc:1079] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/164961225ffc4646a661951030d663c6/wal-000000033 (ops 159-163)
I20260812 06:18:58.527343  3081 log.cc:1079] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/164961225ffc4646a661951030d663c6/wal-000000034 (ops 164-168)
I20260812 06:18:58.527374  3081 log.cc:1079] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/164961225ffc4646a661951030d663c6/wal-000000035 (ops 169-173)
I20260812 06:18:58.527402  3081 log.cc:1079] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/164961225ffc4646a661951030d663c6/wal-000000036 (ops 174-178)
I20260812 06:18:58.527460  3081 log.cc:1079] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/164961225ffc4646a661951030d663c6/wal-000000037 (ops 179-183)
I20260812 06:18:58.527484  3081 log.cc:1079] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/164961225ffc4646a661951030d663c6/wal-000000038 (ops 184-188)
I20260812 06:18:58.552587  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: LogGCOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.026s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:18:58.553032  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling UndoDeltaBlockGCOp(164961225ffc4646a661951030d663c6): 494 bytes on disk
I20260812 06:18:58.553457  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: UndoDeltaBlockGCOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4}
I20260812 06:18:58.554126  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6): perf score=3.181125
I20260812 06:18:58.575054  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.021s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":6238,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:58.575456  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6): perf score=2.188937
I20260812 06:18:58.584690  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.009s	user 0.000s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3463,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:58.585122  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling MajorDeltaCompactionOp(164961225ffc4646a661951030d663c6): perf score=1.000000
I20260812 06:18:58.758484  2905 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.580s	user 1.693s	sys 0.149s
I20260812 06:18:58.787304  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: MajorDeltaCompactionOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.202s	user 0.127s	sys 0.074s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979737,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":12573,"lbm_reads_lt_1ms":770,"lbm_write_time_us":36540,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":3500}
I20260812 06:18:58.787760  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6): perf score=14.095187
I20260812 06:18:58.819473  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: FlushDeltaMemStoresOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.032s	user 0.025s	sys 0.005s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":14857,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:58.820011  3192 maintenance_manager.cc:419] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: Scheduling MajorDeltaCompactionOp(164961225ffc4646a661951030d663c6): perf score=1.000000
I20260812 06:18:58.872012  2905 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.113s	user 0.002s	sys 0.000s
I20260812 06:18:58.872622  2905 tablet_server.cc:179] TabletServer@127.2.214.65:0 shutting down...
I20260812 06:18:58.942700  3081 maintenance_manager.cc:643] P 4ae6a3b0f7024ae396ab1d70bebaa5ea: MajorDeltaCompactionOp(164961225ffc4646a661951030d663c6) complete. Timing: real 0.123s	user 0.093s	sys 0.028s 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":245,"lbm_read_time_us":12594,"lbm_reads_lt_1ms":467,"lbm_write_time_us":22124,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":23,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7936,"update_count":2000}
I20260812 06:18:58.943399  2905 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:58.943822  2905 tablet_replica.cc:333] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea: stopping tablet replica
I20260812 06:18:58.944041  2905 raft_consensus.cc:2243] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:58.944262  2905 raft_consensus.cc:2272] T 164961225ffc4646a661951030d663c6 P 4ae6a3b0f7024ae396ab1d70bebaa5ea [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:58.948781  2905 tablet_server.cc:196] TabletServer@127.2.214.65:0 shutdown complete.
I20260812 06:18:58.988970  2905 master.cc:562] Master@127.2.214.126:41191 shutting down...
I20260812 06:18:58.992619  2905 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 5f611ddc6b204762a69d180fa19caf68 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:58.992763  2905 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 5f611ddc6b204762a69d180fa19caf68 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:58.992815  2905 tablet_replica.cc:333] T 00000000000000000000000000000000 P 5f611ddc6b204762a69d180fa19caf68: stopping tablet replica
I20260812 06:18:59.005602  2905 master.cc:584] Master@127.2.214.126:41191 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5162 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:59.089601  2905 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.2.214.126:40577
I20260812 06:18:59.089984  2905 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:59.091732  3251 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:18:59.091794  3248 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:59.091877  3241 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:59.091965  2905 server_base.cc:1061] running on GCE node
I20260812 06:18:59.092100  2905 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:59.092134  2905 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:59.092149  2905 hybrid_clock.cc:648] HybridClock initialized: now 1786515539092148 us; error 0 us; skew 500 ppm
I20260812 06:18:59.092864  2905 webserver.cc:533] Webserver started at http://127.2.214.126:38423/ using document root <none> and password file <none>
I20260812 06:18:59.092990  2905 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:59.093027  2905 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:59.093080  2905 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:59.093400  2905 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533906135-2905-0/minicluster-data/master-0-root/instance:
uuid: "fc1dedf124d5428c91e0720ff81ad0f0"
format_stamp: "Formatted at 2026-08-12 06:18:59 on dist-test-slave-tc2s"
I20260812 06:18:59.094823  2905 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:18:59.095647  3256 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:59.095861  2905 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:18:59.095924  2905 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533906135-2905-0/minicluster-data/master-0-root
uuid: "fc1dedf124d5428c91e0720ff81ad0f0"
format_stamp: "Formatted at 2026-08-12 06:18:59 on dist-test-slave-tc2s"
I20260812 06:18:59.095990  2905 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533906135-2905-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533906135-2905-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533906135-2905-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:59.112711  2905 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:59.113008  2905 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:59.116770  2905 rpc_server.cc:307] RPC server started. Bound to: 127.2.214.126:40577
I20260812 06:18:59.116796  3349 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.2.214.126:40577 every 8 connection(s)
I20260812 06:18:59.117527  3351 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:59.119215  3351 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P fc1dedf124d5428c91e0720ff81ad0f0: Bootstrap starting.
I20260812 06:18:59.119920  3351 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P fc1dedf124d5428c91e0720ff81ad0f0: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:59.120793  3351 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P fc1dedf124d5428c91e0720ff81ad0f0: No bootstrap required, opened a new log
I20260812 06:18:59.121163  3351 raft_consensus.cc:359] T 00000000000000000000000000000000 P fc1dedf124d5428c91e0720ff81ad0f0 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fc1dedf124d5428c91e0720ff81ad0f0" member_type: VOTER }
I20260812 06:18:59.121243  3351 raft_consensus.cc:385] T 00000000000000000000000000000000 P fc1dedf124d5428c91e0720ff81ad0f0 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:59.121274  3351 raft_consensus.cc:740] T 00000000000000000000000000000000 P fc1dedf124d5428c91e0720ff81ad0f0 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: fc1dedf124d5428c91e0720ff81ad0f0, State: Initialized, Role: FOLLOWER
I20260812 06:18:59.121412  3351 consensus_queue.cc:260] T 00000000000000000000000000000000 P fc1dedf124d5428c91e0720ff81ad0f0 [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: "fc1dedf124d5428c91e0720ff81ad0f0" member_type: VOTER }
I20260812 06:18:59.121481  3351 raft_consensus.cc:399] T 00000000000000000000000000000000 P fc1dedf124d5428c91e0720ff81ad0f0 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:59.121513  3351 raft_consensus.cc:493] T 00000000000000000000000000000000 P fc1dedf124d5428c91e0720ff81ad0f0 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:59.121562  3351 raft_consensus.cc:3060] T 00000000000000000000000000000000 P fc1dedf124d5428c91e0720ff81ad0f0 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:59.122218  3351 raft_consensus.cc:515] T 00000000000000000000000000000000 P fc1dedf124d5428c91e0720ff81ad0f0 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fc1dedf124d5428c91e0720ff81ad0f0" member_type: VOTER }
I20260812 06:18:59.122335  3351 leader_election.cc:304] T 00000000000000000000000000000000 P fc1dedf124d5428c91e0720ff81ad0f0 [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: fc1dedf124d5428c91e0720ff81ad0f0; no voters: 
I20260812 06:18:59.122493  3351 leader_election.cc:290] T 00000000000000000000000000000000 P fc1dedf124d5428c91e0720ff81ad0f0 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:59.122584  3358 raft_consensus.cc:2804] T 00000000000000000000000000000000 P fc1dedf124d5428c91e0720ff81ad0f0 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:59.122771  3358 raft_consensus.cc:697] T 00000000000000000000000000000000 P fc1dedf124d5428c91e0720ff81ad0f0 [term 1 LEADER]: Becoming Leader. State: Replica: fc1dedf124d5428c91e0720ff81ad0f0, State: Running, Role: LEADER
I20260812 06:18:59.122895  3351 sys_catalog.cc:565] T 00000000000000000000000000000000 P fc1dedf124d5428c91e0720ff81ad0f0 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:59.122931  3358 consensus_queue.cc:237] T 00000000000000000000000000000000 P fc1dedf124d5428c91e0720ff81ad0f0 [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: "fc1dedf124d5428c91e0720ff81ad0f0" member_type: VOTER }
I20260812 06:18:59.123324  3359 sys_catalog.cc:455] T 00000000000000000000000000000000 P fc1dedf124d5428c91e0720ff81ad0f0 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "fc1dedf124d5428c91e0720ff81ad0f0" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fc1dedf124d5428c91e0720ff81ad0f0" member_type: VOTER } }
I20260812 06:18:59.123347  3365 sys_catalog.cc:455] T 00000000000000000000000000000000 P fc1dedf124d5428c91e0720ff81ad0f0 [sys.catalog]: SysCatalogTable state changed. Reason: New leader fc1dedf124d5428c91e0720ff81ad0f0. Latest consensus state: current_term: 1 leader_uuid: "fc1dedf124d5428c91e0720ff81ad0f0" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fc1dedf124d5428c91e0720ff81ad0f0" member_type: VOTER } }
I20260812 06:18:59.123474  3365 sys_catalog.cc:458] T 00000000000000000000000000000000 P fc1dedf124d5428c91e0720ff81ad0f0 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:59.123708  3373 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:59.123906  3359 sys_catalog.cc:458] T 00000000000000000000000000000000 P fc1dedf124d5428c91e0720ff81ad0f0 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:59.124539  3373 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:59.124747  2905 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:59.126245  3373 catalog_manager.cc:1383] Generated new cluster ID: afa752514df44c30b216df1f4c9f3269
I20260812 06:18:59.126298  3373 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:59.166087  3373 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:59.166580  3373 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:59.171254  3373 catalog_manager.cc:6092] T 00000000000000000000000000000000 P fc1dedf124d5428c91e0720ff81ad0f0: Generated new TSK 0
I20260812 06:18:59.171389  3373 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:59.189019  2905 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:59.190866  3393 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:59.190855  3398 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:59.190982  2905 server_base.cc:1061] running on GCE node
W20260812 06:18:59.190851  3394 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:59.191259  2905 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:59.191300  2905 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:59.191319  2905 hybrid_clock.cc:648] HybridClock initialized: now 1786515539191319 us; error 0 us; skew 500 ppm
I20260812 06:18:59.192112  2905 webserver.cc:533] Webserver started at http://127.2.214.65:40401/ using document root <none> and password file <none>
I20260812 06:18:59.192270  2905 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:59.192322  2905 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:59.192394  2905 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:59.192754  2905 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533906135-2905-0/minicluster-data/ts-0-root/instance:
uuid: "8d4d0430f46a40e698f8968b778c4cab"
format_stamp: "Formatted at 2026-08-12 06:18:59 on dist-test-slave-tc2s"
I20260812 06:18:59.194166  2905 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:59.195075  3407 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:59.195325  2905 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:18:59.195389  2905 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533906135-2905-0/minicluster-data/ts-0-root
uuid: "8d4d0430f46a40e698f8968b778c4cab"
format_stamp: "Formatted at 2026-08-12 06:18:59 on dist-test-slave-tc2s"
I20260812 06:18:59.195443  2905 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533906135-2905-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533906135-2905-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533906135-2905-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:59.208772  2905 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:59.209049  2905 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:59.209272  2905 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:59.209676  2905 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:59.209709  2905 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:59.209741  2905 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:59.209769  2905 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:59.214089  2905 rpc_server.cc:307] RPC server started. Bound to: 127.2.214.65:33663
I20260812 06:18:59.214126  3513 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.2.214.65:33663 every 8 connection(s)
I20260812 06:18:59.221199  3517 heartbeater.cc:344] Connected to a master server at 127.2.214.126:40577
I20260812 06:18:59.221289  3517 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:59.221481  3517 heartbeater.cc:507] Master 127.2.214.126:40577 requested a full tablet report, sending...
I20260812 06:18:59.222074  3288 ts_manager.cc:194] Registered new tserver with Master: 8d4d0430f46a40e698f8968b778c4cab (127.2.214.65:33663)
I20260812 06:18:59.222256  2905 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.007707107s
I20260812 06:18:59.223001  3288 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:36920
I20260812 06:18:59.228521  3288 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:36932:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:18:59.236140  3451 tablet_service.cc:1511] Processing CreateTablet for tablet 1ee732367fa04da68adbe40a4cfe7b96 (DEFAULT_TABLE table=heavy-update-compaction-test [id=10dff3be7303447b97233939f52f301e]), partition=
I20260812 06:18:59.236351  3451 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 1ee732367fa04da68adbe40a4cfe7b96. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:59.238031  3547 tablet_bootstrap.cc:492] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab: Bootstrap starting.
I20260812 06:18:59.238979  3547 tablet_bootstrap.cc:654] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:59.239892  3547 tablet_bootstrap.cc:492] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab: No bootstrap required, opened a new log
I20260812 06:18:59.239969  3547 ts_tablet_manager.cc:1403] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:18:59.240300  3547 raft_consensus.cc:359] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8d4d0430f46a40e698f8968b778c4cab" member_type: VOTER last_known_addr { host: "127.2.214.65" port: 33663 } }
I20260812 06:18:59.240389  3547 raft_consensus.cc:385] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:59.240417  3547 raft_consensus.cc:740] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 8d4d0430f46a40e698f8968b778c4cab, State: Initialized, Role: FOLLOWER
I20260812 06:18:59.240514  3547 consensus_queue.cc:260] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab [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: "8d4d0430f46a40e698f8968b778c4cab" member_type: VOTER last_known_addr { host: "127.2.214.65" port: 33663 } }
I20260812 06:18:59.240571  3547 raft_consensus.cc:399] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:59.240597  3547 raft_consensus.cc:493] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:59.240629  3547 raft_consensus.cc:3060] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:59.241273  3547 raft_consensus.cc:515] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8d4d0430f46a40e698f8968b778c4cab" member_type: VOTER last_known_addr { host: "127.2.214.65" port: 33663 } }
I20260812 06:18:59.241400  3547 leader_election.cc:304] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab [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: 8d4d0430f46a40e698f8968b778c4cab; no voters: 
I20260812 06:18:59.241582  3547 leader_election.cc:290] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:59.241662  3550 raft_consensus.cc:2804] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:59.241848  3550 raft_consensus.cc:697] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab [term 1 LEADER]: Becoming Leader. State: Replica: 8d4d0430f46a40e698f8968b778c4cab, State: Running, Role: LEADER
I20260812 06:18:59.241958  3547 ts_tablet_manager.cc:1434] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:59.242056  3517 heartbeater.cc:499] Master 127.2.214.126:40577 was elected leader, sending a full tablet report...
I20260812 06:18:59.242062  3550 consensus_queue.cc:237] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab [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: "8d4d0430f46a40e698f8968b778c4cab" member_type: VOTER last_known_addr { host: "127.2.214.65" port: 33663 } }
I20260812 06:18:59.243263  3288 catalog_manager.cc:5719] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab reported cstate change: term changed from 0 to 1, leader changed from <none> to 8d4d0430f46a40e698f8968b778c4cab (127.2.214.65). New cstate: current_term: 1 leader_uuid: "8d4d0430f46a40e698f8968b778c4cab" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8d4d0430f46a40e698f8968b778c4cab" member_type: VOTER last_known_addr { host: "127.2.214.65" port: 33663 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:59.296866  2905 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.050s	user 0.017s	sys 0.004s
I20260812 06:18:59.465046  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling FlushMRSOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=23.023690
I20260812 06:18:59.629679  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: FlushMRSOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.164s	user 0.101s	sys 0.059s Metrics: {"bytes_written":12717735,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":59,"dirs.run_cpu_time_us":208,"dirs.run_wall_time_us":804,"drs_written":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4,"lbm_write_time_us":41533,"lbm_writes_lt_1ms":867,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"spinlock_wait_cycles":1920,"update_count":1550}
I20260812 06:18:59.630347  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling LogGCOp(1ee732367fa04da68adbe40a4cfe7b96): free 20743880 bytes of WAL
I20260812 06:18:59.630592  3417 log_reader.cc:385] T 1ee732367fa04da68adbe40a4cfe7b96: removed 2 log segments from log reader
I20260812 06:18:59.630646  3417 log.cc:1079] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/1ee732367fa04da68adbe40a4cfe7b96/wal-000000001 (ops 1-6)
I20260812 06:18:59.630674  3417 log.cc:1079] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/1ee732367fa04da68adbe40a4cfe7b96/wal-000000002 (ops 7-11)
I20260812 06:18:59.634297  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: LogGCOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.004s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:18:59.634593  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling UndoDeltaBlockGCOp(1ee732367fa04da68adbe40a4cfe7b96): 20513813 bytes on disk
I20260812 06:18:59.634970  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: UndoDeltaBlockGCOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:18:59.635339  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=2.188937
I20260812 06:18:59.654951  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.019s	user 0.009s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5969,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:59.655296  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=2.188937
I20260812 06:18:59.664273  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.009s	user 0.003s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3665,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:59.664644  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling MajorDeltaCompactionOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=1.000000
I20260812 06:18:59.840572  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: MajorDeltaCompactionOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.176s	user 0.105s	sys 0.069s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815794,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":523,"lbm_read_time_us":12026,"lbm_reads_lt_1ms":569,"lbm_write_time_us":27399,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"thread_start_us":284,"threads_started":5,"update_count":2500}
I20260812 06:18:59.841275  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=14.095187
I20260812 06:18:59.891917  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.050s	user 0.027s	sys 0.019s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":16840,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:59.892436  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=2.188937
I20260812 06:18:59.902552  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3990,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:59.902968  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling MajorDeltaCompactionOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=1.000000
I20260812 06:19:00.086392  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: MajorDeltaCompactionOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.183s	user 0.113s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":210,"lbm_read_time_us":11818,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27813,"lbm_writes_lt_1ms":543,"mutex_wait_us":58,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3968,"update_count":2500}
I20260812 06:19:00.087162  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=14.095187
I20260812 06:19:00.133266  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.046s	user 0.021s	sys 0.012s Metrics: {"bytes_written":16409906,"delete_count":0,"lbm_write_time_us":16109,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:00.133684  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=2.188937
I20260812 06:19:00.152729  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.019s	user 0.006s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3635,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:00.153182  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling MajorDeltaCompactionOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=1.000000
I20260812 06:19:00.328037  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: MajorDeltaCompactionOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.175s	user 0.110s	sys 0.055s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":541,"lbm_read_time_us":11756,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25016,"lbm_writes_lt_1ms":543,"mutex_wait_us":283,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":57088,"update_count":2500}
I20260812 06:19:00.330196  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=14.095187
I20260812 06:19:00.382632  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.052s	user 0.040s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21620,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:00.383050  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=2.188937
I20260812 06:19:00.392503  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3560,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:00.393091  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling MajorDeltaCompactionOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=1.000000
I20260812 06:19:00.557057  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: MajorDeltaCompactionOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.164s	user 0.135s	sys 0.020s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":739,"lbm_read_time_us":11024,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27311,"lbm_writes_lt_1ms":543,"mutex_wait_us":297,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:19:00.557544  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=14.095187
I20260812 06:19:00.608239  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.051s	user 0.033s	sys 0.016s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":21188,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:00.608760  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=2.188937
I20260812 06:19:00.620227  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.011s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3840,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:00.620724  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling MajorDeltaCompactionOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=1.000000
I20260812 06:19:00.778061  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: MajorDeltaCompactionOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.157s	user 0.114s	sys 0.031s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1417,"lbm_read_time_us":9001,"lbm_reads_lt_1ms":564,"lbm_write_time_us":27928,"lbm_writes_lt_1ms":543,"mutex_wait_us":972,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1152,"update_count":2500}
I20260812 06:19:00.778651  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=14.095187
I20260812 06:19:00.824803  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.046s	user 0.008s	sys 0.025s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":15533,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:00.825310  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=2.188937
I20260812 06:19:00.840337  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.015s	user 0.000s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5700,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:00.840917  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling FlushMRSOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=1.000000
I20260812 06:19:00.868142  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: FlushMRSOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.027s	user 0.026s	sys 0.000s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":59,"dirs.run_cpu_time_us":230,"dirs.run_wall_time_us":1192,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1553,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:00.868757  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling LogGCOp(1ee732367fa04da68adbe40a4cfe7b96): free 120553369 bytes of WAL
I20260812 06:19:00.868985  3417 log_reader.cc:385] T 1ee732367fa04da68adbe40a4cfe7b96: removed 12 log segments from log reader
I20260812 06:19:00.869032  3417 log.cc:1079] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/1ee732367fa04da68adbe40a4cfe7b96/wal-000000003 (ops 12-16)
I20260812 06:19:00.869060  3417 log.cc:1079] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/1ee732367fa04da68adbe40a4cfe7b96/wal-000000004 (ops 17-21)
I20260812 06:19:00.869076  3417 log.cc:1079] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/1ee732367fa04da68adbe40a4cfe7b96/wal-000000005 (ops 22-26)
I20260812 06:19:00.869105  3417 log.cc:1079] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/1ee732367fa04da68adbe40a4cfe7b96/wal-000000006 (ops 27-31)
I20260812 06:19:00.869135  3417 log.cc:1079] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/1ee732367fa04da68adbe40a4cfe7b96/wal-000000007 (ops 32-36)
I20260812 06:19:00.869167  3417 log.cc:1079] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/1ee732367fa04da68adbe40a4cfe7b96/wal-000000008 (ops 37-40)
I20260812 06:19:00.869199  3417 log.cc:1079] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/1ee732367fa04da68adbe40a4cfe7b96/wal-000000009 (ops 41-45)
I20260812 06:19:00.869230  3417 log.cc:1079] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/1ee732367fa04da68adbe40a4cfe7b96/wal-000000010 (ops 46-50)
I20260812 06:19:00.869261  3417 log.cc:1079] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/1ee732367fa04da68adbe40a4cfe7b96/wal-000000011 (ops 51-54)
I20260812 06:19:00.869292  3417 log.cc:1079] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/1ee732367fa04da68adbe40a4cfe7b96/wal-000000012 (ops 55-59)
I20260812 06:19:00.869323  3417 log.cc:1079] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/1ee732367fa04da68adbe40a4cfe7b96/wal-000000013 (ops 60-64)
I20260812 06:19:00.869354  3417 log.cc:1079] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/1ee732367fa04da68adbe40a4cfe7b96/wal-000000014 (ops 65-69)
I20260812 06:19:00.890499  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: LogGCOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.022s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:19:00.890900  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=3.181125
I20260812 06:19:00.905316  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.014s	user 0.008s	sys 0.002s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4268,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:00.905735  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling UndoDeltaBlockGCOp(1ee732367fa04da68adbe40a4cfe7b96): 472 bytes on disk
I20260812 06:19:00.906111  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: UndoDeltaBlockGCOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4}
I20260812 06:19:00.906581  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=2.188937
I20260812 06:19:00.924328  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.018s	user 0.007s	sys 0.010s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3269,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:00.924723  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling MajorDeltaCompactionOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=1.000000
I20260812 06:19:01.133579  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: MajorDeltaCompactionOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.209s	user 0.139s	sys 0.069s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020734,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":165,"lbm_read_time_us":14821,"lbm_reads_lt_1ms":774,"lbm_write_time_us":32820,"lbm_writes_lt_1ms":743,"mutex_wait_us":43,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":3968,"thread_start_us":70,"threads_started":1,"update_count":3500}
I20260812 06:19:01.134095  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=15.087375
I20260812 06:19:01.197813  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.064s	user 0.022s	sys 0.029s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":21194,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":412,"reinsert_count":0,"update_count":2050}
I20260812 06:19:01.198324  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=6.157687
I20260812 06:19:01.224143  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.026s	user 0.018s	sys 0.007s Metrics: {"bytes_written":7794837,"delete_count":0,"lbm_write_time_us":10979,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:19:01.224622  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling MajorDeltaCompactionOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=1.000000
I20260812 06:19:01.415055  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: MajorDeltaCompactionOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.190s	user 0.138s	sys 0.052s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918096,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":244,"lbm_read_time_us":13379,"lbm_reads_lt_1ms":664,"lbm_write_time_us":29913,"lbm_writes_lt_1ms":643,"mutex_wait_us":45,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":8960,"update_count":3000}
I20260812 06:19:01.415580  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=15.087375
I20260812 06:19:01.458518  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.043s	user 0.033s	sys 0.008s Metrics: {"bytes_written":16820144,"delete_count":0,"lbm_write_time_us":18364,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:19:01.459049  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=2.188937
I20260812 06:19:01.483569  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.024s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5440,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:01.483992  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=2.188937
I20260812 06:19:01.493280  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.009s	user 0.000s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3637,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:01.493685  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling MajorDeltaCompactionOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=1.000000
I20260812 06:19:01.687839  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: MajorDeltaCompactionOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.194s	user 0.130s	sys 0.063s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918203,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":580,"lbm_read_time_us":13394,"lbm_reads_lt_1ms":673,"lbm_write_time_us":33555,"lbm_writes_lt_1ms":643,"mutex_wait_us":338,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":25216,"update_count":3000}
I20260812 06:19:01.688452  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=14.095187
I20260812 06:19:01.737977  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.049s	user 0.017s	sys 0.031s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21668,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:01.738440  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=2.188937
I20260812 06:19:01.750208  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.012s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4583,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:01.750672  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling MajorDeltaCompactionOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=1.000000
I20260812 06:19:01.921856  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: MajorDeltaCompactionOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.171s	user 0.136s	sys 0.033s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":793,"lbm_read_time_us":12258,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29792,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5248,"update_count":2500}
I20260812 06:19:01.922395  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=14.095187
I20260812 06:19:01.975081  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.053s	user 0.027s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21211,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:01.975632  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=2.188937
I20260812 06:19:01.985801  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3896,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:01.986398  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling MajorDeltaCompactionOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=1.000000
I20260812 06:19:02.157027  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: MajorDeltaCompactionOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.170s	user 0.104s	sys 0.057s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":585,"lbm_read_time_us":11762,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28078,"lbm_writes_lt_1ms":543,"mutex_wait_us":274,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2500}
I20260812 06:19:02.157514  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=14.095187
I20260812 06:19:02.209723  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.052s	user 0.023s	sys 0.024s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":17465,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:02.210336  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=2.188937
I20260812 06:19:02.224968  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.014s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5668,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:02.225615  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling FlushMRSOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=1.000000
I20260812 06:19:02.266148  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: FlushMRSOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.040s	user 0.025s	sys 0.004s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":43,"dirs.run_cpu_time_us":173,"dirs.run_wall_time_us":1159,"drs_written":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1575,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:02.266911  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling LogGCOp(1ee732367fa04da68adbe40a4cfe7b96): free 124710250 bytes of WAL
I20260812 06:19:02.267136  3417 log_reader.cc:385] T 1ee732367fa04da68adbe40a4cfe7b96: removed 12 log segments from log reader
I20260812 06:19:02.267184  3417 log.cc:1079] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/1ee732367fa04da68adbe40a4cfe7b96/wal-000000015 (ops 70-74)
I20260812 06:19:02.267223  3417 log.cc:1079] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/1ee732367fa04da68adbe40a4cfe7b96/wal-000000016 (ops 75-79)
I20260812 06:19:02.267257  3417 log.cc:1079] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/1ee732367fa04da68adbe40a4cfe7b96/wal-000000017 (ops 80-84)
I20260812 06:19:02.267283  3417 log.cc:1079] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/1ee732367fa04da68adbe40a4cfe7b96/wal-000000018 (ops 85-89)
I20260812 06:19:02.267314  3417 log.cc:1079] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/1ee732367fa04da68adbe40a4cfe7b96/wal-000000019 (ops 90-94)
I20260812 06:19:02.267341  3417 log.cc:1079] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/1ee732367fa04da68adbe40a4cfe7b96/wal-000000020 (ops 95-99)
I20260812 06:19:02.267373  3417 log.cc:1079] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/1ee732367fa04da68adbe40a4cfe7b96/wal-000000021 (ops 100-104)
I20260812 06:19:02.267403  3417 log.cc:1079] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/1ee732367fa04da68adbe40a4cfe7b96/wal-000000022 (ops 105-109)
I20260812 06:19:02.267434  3417 log.cc:1079] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/1ee732367fa04da68adbe40a4cfe7b96/wal-000000023 (ops 110-114)
I20260812 06:19:02.267462  3417 log.cc:1079] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/1ee732367fa04da68adbe40a4cfe7b96/wal-000000024 (ops 115-119)
I20260812 06:19:02.267493  3417 log.cc:1079] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/1ee732367fa04da68adbe40a4cfe7b96/wal-000000025 (ops 120-124)
I20260812 06:19:02.267521  3417 log.cc:1079] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/1ee732367fa04da68adbe40a4cfe7b96/wal-000000026 (ops 125-129)
I20260812 06:19:02.289850  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: LogGCOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.023s	user 0.000s	sys 0.019s Metrics: {}
I20260812 06:19:02.290266  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling UndoDeltaBlockGCOp(1ee732367fa04da68adbe40a4cfe7b96): 462 bytes on disk
I20260812 06:19:02.290683  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: UndoDeltaBlockGCOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:19:02.291152  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=2.188937
I20260812 06:19:02.308014  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.017s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4168,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:02.308382  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=2.188937
I20260812 06:19:02.322388  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.014s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5425,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:02.322887  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling MajorDeltaCompactionOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=1.000000
I20260812 06:19:02.552517  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: MajorDeltaCompactionOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.229s	user 0.161s	sys 0.056s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020746,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":512,"lbm_read_time_us":15528,"lbm_reads_lt_1ms":774,"lbm_write_time_us":37240,"lbm_writes_lt_1ms":743,"mutex_wait_us":256,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":2304,"thread_start_us":82,"threads_started":1,"update_count":3500}
I20260812 06:19:02.554188  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=18.063937
I20260812 06:19:02.613951  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.060s	user 0.044s	sys 0.016s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":26900,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:02.614490  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=2.188937
I20260812 06:19:02.625531  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4200,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:02.626055  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling MajorDeltaCompactionOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=1.000000
I20260812 06:19:02.805812  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: MajorDeltaCompactionOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.180s	user 0.122s	sys 0.057s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918098,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":122,"lbm_read_time_us":11114,"lbm_reads_lt_1ms":672,"lbm_write_time_us":34914,"lbm_writes_lt_1ms":643,"mutex_wait_us":42,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":3000}
I20260812 06:19:02.806421  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=14.095187
I20260812 06:19:02.852240  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.046s	user 0.020s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20371,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:02.852736  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=2.188937
I20260812 06:19:02.863569  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3830,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:02.863996  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling MajorDeltaCompactionOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=1.000000
I20260812 06:19:03.030090  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: MajorDeltaCompactionOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.166s	user 0.113s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1798,"lbm_read_time_us":9804,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28626,"lbm_writes_lt_1ms":543,"mutex_wait_us":1559,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14336,"update_count":2500}
I20260812 06:19:03.030748  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=14.095187
I20260812 06:19:03.080152  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.049s	user 0.043s	sys 0.004s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22299,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:03.080763  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling MajorDeltaCompactionOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=1.000000
I20260812 06:19:03.230952  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: MajorDeltaCompactionOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.150s	user 0.100s	sys 0.039s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713153,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":223,"lbm_read_time_us":9919,"lbm_reads_lt_1ms":467,"lbm_write_time_us":23381,"lbm_writes_lt_1ms":443,"mutex_wait_us":25,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3328,"update_count":2000}
I20260812 06:19:03.231822  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=14.095187
I20260812 06:19:03.281147  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.049s	user 0.028s	sys 0.011s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20125,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:03.281643  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=2.188937
I20260812 06:19:03.292333  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3987,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:03.292958  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling MajorDeltaCompactionOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=1.000000
I20260812 06:19:03.462981  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: MajorDeltaCompactionOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.170s	user 0.133s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":252,"lbm_read_time_us":11139,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28011,"lbm_writes_lt_1ms":543,"mutex_wait_us":50,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6656,"update_count":2500}
I20260812 06:19:03.463508  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=14.095187
I20260812 06:19:03.508091  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.044s	user 0.018s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17855,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:03.508657  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=2.188937
I20260812 06:19:03.519011  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.010s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3914,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:03.519696  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling MajorDeltaCompactionOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=1.000000
I20260812 06:19:03.667198  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: MajorDeltaCompactionOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.147s	user 0.104s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":238,"lbm_read_time_us":11092,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26591,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":17408,"update_count":2500}
I20260812 06:19:03.667846  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=10.126437
I20260812 06:19:03.702569  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.034s	user 0.031s	sys 0.003s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14557,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:03.703157  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=2.188937
I20260812 06:19:03.718889  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.016s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5011,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:03.719519  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling FlushMRSOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=1.000000
I20260812 06:19:03.768895  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: FlushMRSOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.049s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":1442,"dirs.run_cpu_time_us":168,"dirs.run_wall_time_us":1174,"drs_written":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2108,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:19:03.769577  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling LogGCOp(1ee732367fa04da68adbe40a4cfe7b96): free 133024646 bytes of WAL
I20260812 06:19:03.769781  3417 log_reader.cc:385] T 1ee732367fa04da68adbe40a4cfe7b96: removed 13 log segments from log reader
I20260812 06:19:03.769827  3417 log.cc:1079] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/1ee732367fa04da68adbe40a4cfe7b96/wal-000000027 (ops 130-134)
I20260812 06:19:03.769855  3417 log.cc:1079] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/1ee732367fa04da68adbe40a4cfe7b96/wal-000000028 (ops 135-139)
I20260812 06:19:03.769913  3417 log.cc:1079] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/1ee732367fa04da68adbe40a4cfe7b96/wal-000000029 (ops 140-144)
I20260812 06:19:03.769953  3417 log.cc:1079] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/1ee732367fa04da68adbe40a4cfe7b96/wal-000000030 (ops 145-148)
I20260812 06:19:03.769977  3417 log.cc:1079] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/1ee732367fa04da68adbe40a4cfe7b96/wal-000000031 (ops 149-153)
I20260812 06:19:03.770009  3417 log.cc:1079] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/1ee732367fa04da68adbe40a4cfe7b96/wal-000000032 (ops 154-158)
I20260812 06:19:03.770042  3417 log.cc:1079] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/1ee732367fa04da68adbe40a4cfe7b96/wal-000000033 (ops 159-163)
I20260812 06:19:03.770073  3417 log.cc:1079] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/1ee732367fa04da68adbe40a4cfe7b96/wal-000000034 (ops 164-168)
I20260812 06:19:03.770104  3417 log.cc:1079] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/1ee732367fa04da68adbe40a4cfe7b96/wal-000000035 (ops 169-173)
I20260812 06:19:03.770136  3417 log.cc:1079] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/1ee732367fa04da68adbe40a4cfe7b96/wal-000000036 (ops 174-178)
I20260812 06:19:03.770169  3417 log.cc:1079] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/1ee732367fa04da68adbe40a4cfe7b96/wal-000000037 (ops 179-183)
I20260812 06:19:03.770201  3417 log.cc:1079] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/1ee732367fa04da68adbe40a4cfe7b96/wal-000000038 (ops 184-188)
I20260812 06:19:03.770232  3417 log.cc:1079] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab: Deleting log segment in path: /tmp/dist-test-taskkWdktC/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515533906135-2905-0/minicluster-data/ts-0-root/wals/1ee732367fa04da68adbe40a4cfe7b96/wal-000000039 (ops 189-193)
I20260812 06:19:03.794030  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: LogGCOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.024s	user 0.001s	sys 0.023s Metrics: {}
I20260812 06:19:03.794396  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=6.157687
I20260812 06:19:03.820711  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.026s	user 0.015s	sys 0.008s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":11105,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:03.821219  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=2.188937
I20260812 06:19:03.844300  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: FlushDeltaMemStoresOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.023s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6314,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:03.845016  3524 maintenance_manager.cc:419] P 8d4d0430f46a40e698f8968b778c4cab: Scheduling MajorDeltaCompactionOp(1ee732367fa04da68adbe40a4cfe7b96): perf score=1.000000
I20260812 06:19:03.930900  2905 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.634s	user 1.728s	sys 0.136s
I20260812 06:19:04.034607  2905 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.103s	user 0.002s	sys 0.000s
I20260812 06:19:04.035068  2905 tablet_server.cc:179] TabletServer@127.2.214.65:0 shutting down...
I20260812 06:19:04.057245  3417 maintenance_manager.cc:643] P 8d4d0430f46a40e698f8968b778c4cab: MajorDeltaCompactionOp(1ee732367fa04da68adbe40a4cfe7b96) complete. Timing: real 0.212s	user 0.152s	sys 0.060s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020746,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":765,"lbm_read_time_us":15254,"lbm_reads_lt_1ms":762,"lbm_write_time_us":33433,"lbm_writes_lt_1ms":743,"mutex_wait_us":40,"peak_mem_usage":87969044,"reinsert_count":0,"thread_start_us":62,"threads_started":1,"update_count":3500}
I20260812 06:19:04.058132  2905 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:04.058346  2905 tablet_replica.cc:333] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab: stopping tablet replica
I20260812 06:19:04.058511  2905 raft_consensus.cc:2243] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:04.058691  2905 raft_consensus.cc:2272] T 1ee732367fa04da68adbe40a4cfe7b96 P 8d4d0430f46a40e698f8968b778c4cab [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:04.074581  2905 tablet_server.cc:196] TabletServer@127.2.214.65:0 shutdown complete.
I20260812 06:19:04.112589  2905 master.cc:562] Master@127.2.214.126:40577 shutting down...
I20260812 06:19:04.115809  2905 raft_consensus.cc:2243] T 00000000000000000000000000000000 P fc1dedf124d5428c91e0720ff81ad0f0 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:04.115963  2905 raft_consensus.cc:2272] T 00000000000000000000000000000000 P fc1dedf124d5428c91e0720ff81ad0f0 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:04.116014  2905 tablet_replica.cc:333] T 00000000000000000000000000000000 P fc1dedf124d5428c91e0720ff81ad0f0: stopping tablet replica
I20260812 06:19:04.128206  2905 master.cc:584] Master@127.2.214.126:40577 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5133 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10296 ms total)

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