[==========] 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:20:20.931749  1148 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.1.31.62:37501
I20260812 06:20:20.932878  1148 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:20:20.933501  1148 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:20.940054  1154 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:20:20.940056  1157 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:20:20.940126  1148 server_base.cc:1061] running on GCE node
W20260812 06:20:20.940266  1153 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:20:20.940755  1148 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:20.940892  1148 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:20:20.940943  1148 hybrid_clock.cc:648] HybridClock initialized: now 1786515620940940 us; error 0 us; skew 500 ppm
I20260812 06:20:20.942868  1148 webserver.cc:533] Webserver started at http://127.1.31.62:39699/ using document root <none> and password file <none>
I20260812 06:20:20.943437  1148 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:20.943531  1148 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:20.943792  1148 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:20.945587  1148 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620920920-1148-0/minicluster-data/master-0-root/instance:
uuid: "8d3c3523dc7c4d358779d218a88b7b8e"
format_stamp: "Formatted at 2026-08-12 06:20:20 on dist-test-slave-mvvj"
I20260812 06:20:20.949199  1148 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.003s	sys 0.002s
I20260812 06:20:20.951298  1162 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:20:20.952385  1148 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.001s
I20260812 06:20:20.952528  1148 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620920920-1148-0/minicluster-data/master-0-root
uuid: "8d3c3523dc7c4d358779d218a88b7b8e"
format_stamp: "Formatted at 2026-08-12 06:20:20 on dist-test-slave-mvvj"
I20260812 06:20:20.952641  1148 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620920920-1148-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620920920-1148-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620920920-1148-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:20:20.973254  1148 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:20.973953  1148 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:20:20.974144  1148 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:20.982151  1148 rpc_server.cc:307] RPC server started. Bound to: 127.1.31.62:37501
I20260812 06:20:20.982164  1223 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.1.31.62:37501 every 8 connection(s)
I20260812 06:20:20.984637  1224 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:20:20.990162  1224 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 8d3c3523dc7c4d358779d218a88b7b8e: Bootstrap starting.
I20260812 06:20:20.992652  1224 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 8d3c3523dc7c4d358779d218a88b7b8e: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:20.993669  1224 log.cc:826] T 00000000000000000000000000000000 P 8d3c3523dc7c4d358779d218a88b7b8e: Log is configured to *not* fsync() on all Append() calls
I20260812 06:20:20.995496  1224 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 8d3c3523dc7c4d358779d218a88b7b8e: No bootstrap required, opened a new log
I20260812 06:20:20.998512  1224 raft_consensus.cc:359] T 00000000000000000000000000000000 P 8d3c3523dc7c4d358779d218a88b7b8e [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8d3c3523dc7c4d358779d218a88b7b8e" member_type: VOTER }
I20260812 06:20:20.998682  1224 raft_consensus.cc:385] T 00000000000000000000000000000000 P 8d3c3523dc7c4d358779d218a88b7b8e [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:20.998754  1224 raft_consensus.cc:740] T 00000000000000000000000000000000 P 8d3c3523dc7c4d358779d218a88b7b8e [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 8d3c3523dc7c4d358779d218a88b7b8e, State: Initialized, Role: FOLLOWER
I20260812 06:20:20.999466  1224 consensus_queue.cc:260] T 00000000000000000000000000000000 P 8d3c3523dc7c4d358779d218a88b7b8e [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: "8d3c3523dc7c4d358779d218a88b7b8e" member_type: VOTER }
I20260812 06:20:20.999617  1224 raft_consensus.cc:399] T 00000000000000000000000000000000 P 8d3c3523dc7c4d358779d218a88b7b8e [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:20.999707  1224 raft_consensus.cc:493] T 00000000000000000000000000000000 P 8d3c3523dc7c4d358779d218a88b7b8e [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:20.999888  1224 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 8d3c3523dc7c4d358779d218a88b7b8e [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:21.000734  1224 raft_consensus.cc:515] T 00000000000000000000000000000000 P 8d3c3523dc7c4d358779d218a88b7b8e [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8d3c3523dc7c4d358779d218a88b7b8e" member_type: VOTER }
I20260812 06:20:21.001190  1224 leader_election.cc:304] T 00000000000000000000000000000000 P 8d3c3523dc7c4d358779d218a88b7b8e [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: 8d3c3523dc7c4d358779d218a88b7b8e; no voters: 
I20260812 06:20:21.001538  1224 leader_election.cc:290] T 00000000000000000000000000000000 P 8d3c3523dc7c4d358779d218a88b7b8e [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:21.001755  1227 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 8d3c3523dc7c4d358779d218a88b7b8e [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:21.002030  1227 raft_consensus.cc:697] T 00000000000000000000000000000000 P 8d3c3523dc7c4d358779d218a88b7b8e [term 1 LEADER]: Becoming Leader. State: Replica: 8d3c3523dc7c4d358779d218a88b7b8e, State: Running, Role: LEADER
I20260812 06:20:21.002514  1227 consensus_queue.cc:237] T 00000000000000000000000000000000 P 8d3c3523dc7c4d358779d218a88b7b8e [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: "8d3c3523dc7c4d358779d218a88b7b8e" member_type: VOTER }
I20260812 06:20:21.002599  1224 sys_catalog.cc:565] T 00000000000000000000000000000000 P 8d3c3523dc7c4d358779d218a88b7b8e [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:21.004545  1229 sys_catalog.cc:455] T 00000000000000000000000000000000 P 8d3c3523dc7c4d358779d218a88b7b8e [sys.catalog]: SysCatalogTable state changed. Reason: New leader 8d3c3523dc7c4d358779d218a88b7b8e. Latest consensus state: current_term: 1 leader_uuid: "8d3c3523dc7c4d358779d218a88b7b8e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8d3c3523dc7c4d358779d218a88b7b8e" member_type: VOTER } }
I20260812 06:20:21.004606  1228 sys_catalog.cc:455] T 00000000000000000000000000000000 P 8d3c3523dc7c4d358779d218a88b7b8e [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "8d3c3523dc7c4d358779d218a88b7b8e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8d3c3523dc7c4d358779d218a88b7b8e" member_type: VOTER } }
I20260812 06:20:21.004674  1229 sys_catalog.cc:458] T 00000000000000000000000000000000 P 8d3c3523dc7c4d358779d218a88b7b8e [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:21.004693  1228 sys_catalog.cc:458] T 00000000000000000000000000000000 P 8d3c3523dc7c4d358779d218a88b7b8e [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:21.005029  1241 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:21.005123  1148 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:21.007313  1241 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:21.012475  1241 catalog_manager.cc:1383] Generated new cluster ID: e7e1d4a69b3249b5b46cb2f3f1c4da00
I20260812 06:20:21.012567  1241 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:21.039088  1241 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:21.040057  1241 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:21.050441  1241 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 8d3c3523dc7c4d358779d218a88b7b8e: Generated new TSK 0
I20260812 06:20:21.051105  1241 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:21.070004  1148 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:21.073073  1249 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:20:21.073076  1248 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:20:21.073158  1251 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:20:21.073501  1148 server_base.cc:1061] running on GCE node
I20260812 06:20:21.073701  1148 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:21.073767  1148 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:20:21.073801  1148 hybrid_clock.cc:648] HybridClock initialized: now 1786515621073801 us; error 0 us; skew 500 ppm
I20260812 06:20:21.074851  1148 webserver.cc:533] Webserver started at http://127.1.31.1:34449/ using document root <none> and password file <none>
I20260812 06:20:21.075049  1148 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:21.075124  1148 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:21.075205  1148 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:21.075624  1148 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620920920-1148-0/minicluster-data/ts-0-root/instance:
uuid: "63045723b1624fa28dd2938f19d74c0e"
format_stamp: "Formatted at 2026-08-12 06:20:21 on dist-test-slave-mvvj"
I20260812 06:20:21.077248  1148 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:21.078332  1256 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:20:21.078590  1148 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:21.078666  1148 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620920920-1148-0/minicluster-data/ts-0-root
uuid: "63045723b1624fa28dd2938f19d74c0e"
format_stamp: "Formatted at 2026-08-12 06:20:21 on dist-test-slave-mvvj"
I20260812 06:20:21.078758  1148 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620920920-1148-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620920920-1148-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620920920-1148-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:20:21.089792  1148 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:21.090283  1148 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:21.090814  1148 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:21.091719  1148 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:21.091773  1148 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:21.091879  1148 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:21.091917  1148 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:21.098948  1148 rpc_server.cc:307] RPC server started. Bound to: 127.1.31.1:40991
I20260812 06:20:21.099030  1326 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.1.31.1:40991 every 8 connection(s)
I20260812 06:20:21.112425  1327 heartbeater.cc:344] Connected to a master server at 127.1.31.62:37501
I20260812 06:20:21.112728  1327 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:21.113240  1327 heartbeater.cc:507] Master 127.1.31.62:37501 requested a full tablet report, sending...
I20260812 06:20:21.114745  1181 ts_manager.cc:194] Registered new tserver with Master: 63045723b1624fa28dd2938f19d74c0e (127.1.31.1:40991)
I20260812 06:20:21.115361  1148 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.015743476s
I20260812 06:20:21.116233  1181 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:50068
I20260812 06:20:21.125557  1181 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:50074:
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:20:21.140618  1287 tablet_service.cc:1511] Processing CreateTablet for tablet d25e7f2f38e24893aa598b72b9c43347 (DEFAULT_TABLE table=heavy-update-compaction-test [id=87b21ebfa5b24e15b0ae4c1c624c934c]), partition=
I20260812 06:20:21.141036  1287 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet d25e7f2f38e24893aa598b72b9c43347. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:21.143550  1340 tablet_bootstrap.cc:492] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e: Bootstrap starting.
I20260812 06:20:21.145067  1340 tablet_bootstrap.cc:654] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:21.146868  1340 tablet_bootstrap.cc:492] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e: No bootstrap required, opened a new log
I20260812 06:20:21.146996  1340 ts_tablet_manager.cc:1403] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e: Time spent bootstrapping tablet: real 0.004s	user 0.003s	sys 0.000s
I20260812 06:20:21.147671  1340 raft_consensus.cc:359] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "63045723b1624fa28dd2938f19d74c0e" member_type: VOTER last_known_addr { host: "127.1.31.1" port: 40991 } }
I20260812 06:20:21.147883  1340 raft_consensus.cc:385] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:21.147971  1340 raft_consensus.cc:740] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 63045723b1624fa28dd2938f19d74c0e, State: Initialized, Role: FOLLOWER
I20260812 06:20:21.148176  1340 consensus_queue.cc:260] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e [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: "63045723b1624fa28dd2938f19d74c0e" member_type: VOTER last_known_addr { host: "127.1.31.1" port: 40991 } }
I20260812 06:20:21.148295  1340 raft_consensus.cc:399] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:21.148340  1340 raft_consensus.cc:493] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:21.148383  1340 raft_consensus.cc:3060] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:21.149456  1340 raft_consensus.cc:515] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "63045723b1624fa28dd2938f19d74c0e" member_type: VOTER last_known_addr { host: "127.1.31.1" port: 40991 } }
I20260812 06:20:21.149616  1340 leader_election.cc:304] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e [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: 63045723b1624fa28dd2938f19d74c0e; no voters: 
I20260812 06:20:21.149860  1340 leader_election.cc:290] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:21.149995  1342 raft_consensus.cc:2804] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:21.150223  1340 ts_tablet_manager.cc:1434] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e: Time spent starting tablet: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:20:21.150290  1342 raft_consensus.cc:697] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e [term 1 LEADER]: Becoming Leader. State: Replica: 63045723b1624fa28dd2938f19d74c0e, State: Running, Role: LEADER
I20260812 06:20:21.150488  1327 heartbeater.cc:499] Master 127.1.31.62:37501 was elected leader, sending a full tablet report...
I20260812 06:20:21.150460  1342 consensus_queue.cc:237] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e [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: "63045723b1624fa28dd2938f19d74c0e" member_type: VOTER last_known_addr { host: "127.1.31.1" port: 40991 } }
I20260812 06:20:21.153362  1180 catalog_manager.cc:5719] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e reported cstate change: term changed from 0 to 1, leader changed from <none> to 63045723b1624fa28dd2938f19d74c0e (127.1.31.1). New cstate: current_term: 1 leader_uuid: "63045723b1624fa28dd2938f19d74c0e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "63045723b1624fa28dd2938f19d74c0e" member_type: VOTER last_known_addr { host: "127.1.31.1" port: 40991 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:21.224017  1148 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.061s	user 0.020s	sys 0.012s
I20260812 06:20:21.350324  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling FlushMRSOp(d25e7f2f38e24893aa598b72b9c43347): perf score=15.086190
I20260812 06:20:21.516858  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: FlushMRSOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.166s	user 0.132s	sys 0.032s Metrics: {"bytes_written":12922857,"cfile_init":1,"compiler_manager_pool.queue_time_us":202,"delete_count":0,"dirs.queue_time_us":83,"dirs.run_cpu_time_us":235,"dirs.run_wall_time_us":1007,"drs_written":1,"lbm_read_time_us":71,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40427,"lbm_writes_lt_1ms":682,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":319616,"thread_start_us":128,"threads_started":1,"update_count":1575}
I20260812 06:20:21.518062  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling LogGCOp(d25e7f2f38e24893aa598b72b9c43347): free 20743880 bytes of WAL
I20260812 06:20:21.518400  1262 log_reader.cc:385] T d25e7f2f38e24893aa598b72b9c43347: removed 2 log segments from log reader
I20260812 06:20:21.518482  1262 log.cc:1079] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/d25e7f2f38e24893aa598b72b9c43347/wal-000000001 (ops 1-6)
I20260812 06:20:21.518532  1262 log.cc:1079] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/d25e7f2f38e24893aa598b72b9c43347/wal-000000002 (ops 7-11)
I20260812 06:20:21.523635  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: LogGCOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.005s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:20:21.524092  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling UndoDeltaBlockGCOp(d25e7f2f38e24893aa598b72b9c43347): 12719216 bytes on disk
I20260812 06:20:21.524817  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: UndoDeltaBlockGCOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4}
I20260812 06:20:21.525305  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347): perf score=5.165500
I20260812 06:20:21.546587  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.021s	user 0.011s	sys 0.008s Metrics: {"bytes_written":6728213,"delete_count":0,"lbm_write_time_us":8938,"lbm_writes_lt_1ms":167,"reinsert_count":0,"update_count":820}
I20260812 06:20:21.547072  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling MajorDeltaCompactionOp(d25e7f2f38e24893aa598b72b9c43347): perf score=1.000000
I20260812 06:20:21.714221  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: MajorDeltaCompactionOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.167s	user 0.122s	sys 0.041s Metrics: {"cfile_cache_miss":511,"cfile_cache_miss_bytes":23913192,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":680,"lbm_read_time_us":10653,"lbm_reads_lt_1ms":543,"lbm_write_time_us":30936,"lbm_writes_lt_1ms":522,"peak_mem_usage":60173397,"reinsert_count":0,"thread_start_us":364,"threads_started":5,"update_count":2395}
I20260812 06:20:21.714951  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347): perf score=11.118625
I20260812 06:20:21.754105  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.039s	user 0.016s	sys 0.020s Metrics: {"bytes_written":13169004,"delete_count":0,"lbm_write_time_us":17167,"lbm_writes_lt_1ms":324,"reinsert_count":0,"update_count":1605}
I20260812 06:20:21.754822  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347): perf score=2.188937
I20260812 06:20:21.772612  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.017s	user 0.004s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5122,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:21.773237  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling MajorDeltaCompactionOp(d25e7f2f38e24893aa598b72b9c43347): perf score=1.000000
I20260812 06:20:21.905951  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: MajorDeltaCompactionOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.133s	user 0.088s	sys 0.045s Metrics: {"cfile_cache_miss":443,"cfile_cache_miss_bytes":21123537,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":360,"lbm_read_time_us":7387,"lbm_reads_lt_1ms":475,"lbm_write_time_us":28236,"lbm_writes_lt_1ms":454,"mutex_wait_us":4,"peak_mem_usage":51140713,"reinsert_count":0,"update_count":2055}
I20260812 06:20:21.906703  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347): perf score=11.118625
I20260812 06:20:21.940636  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.034s	user 0.021s	sys 0.011s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14638,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:21.941154  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347): perf score=2.188937
I20260812 06:20:21.957564  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.016s	user 0.014s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6111,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:21.958086  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling MajorDeltaCompactionOp(d25e7f2f38e24893aa598b72b9c43347): perf score=1.000000
I20260812 06:20:22.096036  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: MajorDeltaCompactionOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.138s	user 0.092s	sys 0.046s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":200,"lbm_read_time_us":7630,"lbm_reads_lt_1ms":468,"lbm_write_time_us":29351,"lbm_writes_lt_1ms":443,"mutex_wait_us":19,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8960,"update_count":2000}
I20260812 06:20:22.096657  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347): perf score=10.126437
I20260812 06:20:22.135728  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.039s	user 0.019s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13447,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:22.136492  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347): perf score=2.188937
I20260812 06:20:22.148952  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.012s	user 0.006s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4543,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.149569  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling MajorDeltaCompactionOp(d25e7f2f38e24893aa598b72b9c43347): perf score=1.000000
I20260812 06:20:22.285925  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: MajorDeltaCompactionOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.136s	user 0.080s	sys 0.056s 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":192,"lbm_read_time_us":9711,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22188,"lbm_writes_lt_1ms":443,"mutex_wait_us":96,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:20:22.286568  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347): perf score=10.126437
I20260812 06:20:22.323239  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.037s	user 0.020s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15233,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:22.323956  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347): perf score=2.188937
I20260812 06:20:22.334904  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4196,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.335402  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling MajorDeltaCompactionOp(d25e7f2f38e24893aa598b72b9c43347): perf score=1.000000
I20260812 06:20:22.474849  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: MajorDeltaCompactionOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.139s	user 0.098s	sys 0.039s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":162,"lbm_read_time_us":8437,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27613,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:22.475557  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347): perf score=10.126437
I20260812 06:20:22.514386  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.039s	user 0.024s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16152,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:22.514956  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347): perf score=2.188937
I20260812 06:20:22.532567  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.017s	user 0.012s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6031,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.533142  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling MajorDeltaCompactionOp(d25e7f2f38e24893aa598b72b9c43347): perf score=1.000000
I20260812 06:20:22.670258  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: MajorDeltaCompactionOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.137s	user 0.110s	sys 0.026s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":179,"lbm_read_time_us":7853,"lbm_reads_lt_1ms":464,"lbm_write_time_us":30166,"lbm_writes_lt_1ms":443,"mutex_wait_us":24,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12160,"update_count":2000}
I20260812 06:20:22.670976  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347): perf score=10.126437
I20260812 06:20:22.714625  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.043s	user 0.019s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18251,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":7936,"update_count":1500}
I20260812 06:20:22.715209  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347): perf score=2.188937
I20260812 06:20:22.731089  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.016s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5782,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.731637  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling FlushMRSOp(d25e7f2f38e24893aa598b72b9c43347): perf score=1.000000
I20260812 06:20:22.759598  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: FlushMRSOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.028s	user 0.020s	sys 0.004s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":83,"dirs.run_cpu_time_us":243,"dirs.run_wall_time_us":1695,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1620,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:22.760445  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling LogGCOp(d25e7f2f38e24893aa598b72b9c43347): free 111786275 bytes of WAL
I20260812 06:20:22.760663  1262 log_reader.cc:385] T d25e7f2f38e24893aa598b72b9c43347: removed 11 log segments from log reader
I20260812 06:20:22.760707  1262 log.cc:1079] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/d25e7f2f38e24893aa598b72b9c43347/wal-000000003 (ops 12-16)
I20260812 06:20:22.760736  1262 log.cc:1079] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/d25e7f2f38e24893aa598b72b9c43347/wal-000000004 (ops 17-20)
I20260812 06:20:22.760799  1262 log.cc:1079] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/d25e7f2f38e24893aa598b72b9c43347/wal-000000005 (ops 21-25)
I20260812 06:20:22.760834  1262 log.cc:1079] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/d25e7f2f38e24893aa598b72b9c43347/wal-000000006 (ops 26-30)
I20260812 06:20:22.760869  1262 log.cc:1079] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/d25e7f2f38e24893aa598b72b9c43347/wal-000000007 (ops 31-35)
I20260812 06:20:22.760933  1262 log.cc:1079] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/d25e7f2f38e24893aa598b72b9c43347/wal-000000008 (ops 36-40)
I20260812 06:20:22.760973  1262 log.cc:1079] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/d25e7f2f38e24893aa598b72b9c43347/wal-000000009 (ops 41-45)
I20260812 06:20:22.761011  1262 log.cc:1079] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/d25e7f2f38e24893aa598b72b9c43347/wal-000000010 (ops 46-50)
I20260812 06:20:22.761049  1262 log.cc:1079] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/d25e7f2f38e24893aa598b72b9c43347/wal-000000011 (ops 51-55)
I20260812 06:20:22.761086  1262 log.cc:1079] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/d25e7f2f38e24893aa598b72b9c43347/wal-000000012 (ops 56-60)
I20260812 06:20:22.761123  1262 log.cc:1079] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/d25e7f2f38e24893aa598b72b9c43347/wal-000000013 (ops 61-64)
I20260812 06:20:22.784804  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: LogGCOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.024s	user 0.004s	sys 0.019s Metrics: {}
I20260812 06:20:22.785279  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling UndoDeltaBlockGCOp(d25e7f2f38e24893aa598b72b9c43347): 448 bytes on disk
I20260812 06:20:22.785959  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: UndoDeltaBlockGCOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4}
I20260812 06:20:22.786486  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347): perf score=3.181125
I20260812 06:20:22.807049  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.020s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":7162,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:22.807508  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347): perf score=2.188937
I20260812 06:20:22.817417  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3404,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:22.817903  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling MajorDeltaCompactionOp(d25e7f2f38e24893aa598b72b9c43347): perf score=1.000000
I20260812 06:20:23.011420  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: MajorDeltaCompactionOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.193s	user 0.168s	sys 0.013s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877326,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":283,"lbm_read_time_us":11615,"lbm_reads_lt_1ms":674,"lbm_write_time_us":40172,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":642,"mutex_wait_us":277,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6144,"thread_start_us":91,"threads_started":1,"update_count":3000}
I20260812 06:20:23.012225  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347): perf score=14.095187
I20260812 06:20:23.064738  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.052s	user 0.044s	sys 0.007s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22717,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:23.065220  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347): perf score=2.188937
I20260812 06:20:23.078382  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5131,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.078958  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling MajorDeltaCompactionOp(d25e7f2f38e24893aa598b72b9c43347): perf score=1.000000
I20260812 06:20:23.239185  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: MajorDeltaCompactionOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.160s	user 0.114s	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":1009,"lbm_read_time_us":10820,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29987,"lbm_writes_lt_1ms":543,"mutex_wait_us":299,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12800,"update_count":2500}
I20260812 06:20:23.239810  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347): perf score=14.095187
I20260812 06:20:23.291177  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.051s	user 0.016s	sys 0.029s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23340,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:23.291884  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling MajorDeltaCompactionOp(d25e7f2f38e24893aa598b72b9c43347): perf score=1.000000
I20260812 06:20:23.454319  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: MajorDeltaCompactionOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.162s	user 0.103s	sys 0.048s 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":381,"lbm_read_time_us":10358,"lbm_reads_lt_1ms":463,"lbm_write_time_us":24444,"lbm_writes_lt_1ms":443,"mutex_wait_us":61,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3968,"update_count":2000}
I20260812 06:20:23.455066  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347): perf score=14.095187
I20260812 06:20:23.504516  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.049s	user 0.024s	sys 0.022s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24254,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":400,"reinsert_count":0,"update_count":2000}
I20260812 06:20:23.505128  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347): perf score=2.188937
I20260812 06:20:23.516800  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3862,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.517520  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling MajorDeltaCompactionOp(d25e7f2f38e24893aa598b72b9c43347): perf score=1.000000
I20260812 06:20:23.727946  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: MajorDeltaCompactionOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.210s	user 0.149s	sys 0.045s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1000,"lbm_read_time_us":12312,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33837,"lbm_writes_lt_1ms":543,"mutex_wait_us":270,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12416,"update_count":2500}
I20260812 06:20:23.728700  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347): perf score=14.095187
I20260812 06:20:23.782111  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.053s	user 0.019s	sys 0.032s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23252,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:23.782645  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347): perf score=2.188937
I20260812 06:20:23.794131  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4163,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.794626  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling MajorDeltaCompactionOp(d25e7f2f38e24893aa598b72b9c43347): perf score=1.000000
I20260812 06:20:23.957134  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: MajorDeltaCompactionOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.162s	user 0.108s	sys 0.050s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":285,"lbm_read_time_us":11173,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31466,"lbm_writes_lt_1ms":543,"mutex_wait_us":77,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7296,"update_count":2500}
I20260812 06:20:23.957846  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347): perf score=11.118625
I20260812 06:20:24.009023  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.051s	user 0.025s	sys 0.020s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":18118,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:24.009524  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347): perf score=2.188937
I20260812 06:20:24.020498  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4218,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.020972  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347): perf score=2.188937
I20260812 06:20:24.030565  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3493,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:24.031112  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling MajorDeltaCompactionOp(d25e7f2f38e24893aa598b72b9c43347): perf score=1.000000
I20260812 06:20:24.177352  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: MajorDeltaCompactionOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.146s	user 0.092s	sys 0.054s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774800,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":147,"lbm_read_time_us":9842,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31066,"lbm_writes_lt_1ms":543,"mutex_wait_us":41,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9728,"update_count":2500}
I20260812 06:20:24.178362  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347): perf score=10.126437
I20260812 06:20:24.219436  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.041s	user 0.014s	sys 0.022s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17580,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:24.220110  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347): perf score=2.188937
I20260812 06:20:24.243692  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.023s	user 0.016s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":7560,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.244223  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling FlushMRSOp(d25e7f2f38e24893aa598b72b9c43347): perf score=1.000000
I20260812 06:20:24.294876  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: FlushMRSOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.050s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":74,"dirs.run_cpu_time_us":217,"dirs.run_wall_time_us":1607,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1656,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:24.295811  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling LogGCOp(d25e7f2f38e24893aa598b72b9c43347): free 121006383 bytes of WAL
I20260812 06:20:24.296113  1262 log_reader.cc:385] T d25e7f2f38e24893aa598b72b9c43347: removed 12 log segments from log reader
I20260812 06:20:24.296183  1262 log.cc:1079] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/d25e7f2f38e24893aa598b72b9c43347/wal-000000014 (ops 65-69)
I20260812 06:20:24.296238  1262 log.cc:1079] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/d25e7f2f38e24893aa598b72b9c43347/wal-000000015 (ops 70-74)
I20260812 06:20:24.296296  1262 log.cc:1079] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/d25e7f2f38e24893aa598b72b9c43347/wal-000000016 (ops 75-79)
I20260812 06:20:24.296336  1262 log.cc:1079] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/d25e7f2f38e24893aa598b72b9c43347/wal-000000017 (ops 80-84)
I20260812 06:20:24.296371  1262 log.cc:1079] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/d25e7f2f38e24893aa598b72b9c43347/wal-000000018 (ops 85-88)
I20260812 06:20:24.296408  1262 log.cc:1079] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/d25e7f2f38e24893aa598b72b9c43347/wal-000000019 (ops 89-93)
I20260812 06:20:24.296444  1262 log.cc:1079] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/d25e7f2f38e24893aa598b72b9c43347/wal-000000020 (ops 94-98)
I20260812 06:20:24.296491  1262 log.cc:1079] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/d25e7f2f38e24893aa598b72b9c43347/wal-000000021 (ops 99-103)
I20260812 06:20:24.296527  1262 log.cc:1079] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/d25e7f2f38e24893aa598b72b9c43347/wal-000000022 (ops 104-108)
I20260812 06:20:24.296566  1262 log.cc:1079] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/d25e7f2f38e24893aa598b72b9c43347/wal-000000023 (ops 109-113)
I20260812 06:20:24.296603  1262 log.cc:1079] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/d25e7f2f38e24893aa598b72b9c43347/wal-000000024 (ops 114-118)
I20260812 06:20:24.296638  1262 log.cc:1079] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/d25e7f2f38e24893aa598b72b9c43347/wal-000000025 (ops 119-123)
I20260812 06:20:24.323089  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: LogGCOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.027s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:20:24.323776  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling UndoDeltaBlockGCOp(d25e7f2f38e24893aa598b72b9c43347): 482 bytes on disk
I20260812 06:20:24.324282  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: UndoDeltaBlockGCOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4}
I20260812 06:20:24.324828  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347): perf score=7.149875
I20260812 06:20:24.345130  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.020s	user 0.010s	sys 0.009s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":8715,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:20:24.345615  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling LogGCOp(d25e7f2f38e24893aa598b72b9c43347): free 12017983 bytes of WAL
I20260812 06:20:24.345858  1262 log_reader.cc:385] T d25e7f2f38e24893aa598b72b9c43347: removed 1 log segments from log reader
I20260812 06:20:24.345907  1262 log.cc:1079] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/d25e7f2f38e24893aa598b72b9c43347/wal-000000026 (ops 124-128)
I20260812 06:20:24.348290  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: LogGCOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.002s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:20:24.348726  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347): perf score=2.188937
I20260812 06:20:24.370844  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.022s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5024,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:24.371336  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling MajorDeltaCompactionOp(d25e7f2f38e24893aa598b72b9c43347): perf score=1.000000
I20260812 06:20:24.587088  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: MajorDeltaCompactionOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.216s	user 0.143s	sys 0.072s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979743,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":612,"lbm_read_time_us":15333,"lbm_reads_lt_1ms":766,"lbm_write_time_us":37488,"lbm_writes_lt_1ms":743,"mutex_wait_us":68,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":7168,"thread_start_us":96,"threads_started":1,"update_count":3500}
I20260812 06:20:24.587781  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347): perf score=15.087375
I20260812 06:20:24.652788  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.065s	user 0.037s	sys 0.025s Metrics: {"bytes_written":16820161,"delete_count":0,"lbm_write_time_us":24293,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:20:24.653306  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347): perf score=3.181125
I20260812 06:20:24.668313  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.015s	user 0.014s	sys 0.000s Metrics: {"bytes_written":5087238,"delete_count":0,"lbm_write_time_us":5767,"lbm_writes_lt_1ms":127,"reinsert_count":0,"update_count":620}
I20260812 06:20:24.668915  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347): perf score=1.196750
I20260812 06:20:24.680302  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.011s	user 0.003s	sys 0.008s Metrics: {"bytes_written":2707805,"delete_count":0,"lbm_write_time_us":3901,"lbm_writes_lt_1ms":69,"reinsert_count":0,"update_count":330}
I20260812 06:20:24.680936  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling MajorDeltaCompactionOp(d25e7f2f38e24893aa598b72b9c43347): perf score=1.000000
I20260812 06:20:24.883914  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: MajorDeltaCompactionOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.203s	user 0.130s	sys 0.067s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877204,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":640,"lbm_read_time_us":14335,"lbm_reads_lt_1ms":673,"lbm_write_time_us":33521,"lbm_writes_lt_1ms":643,"mutex_wait_us":22,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":760960,"update_count":3000}
I20260812 06:20:24.884527  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347): perf score=14.095187
I20260812 06:20:24.939589  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.055s	user 0.032s	sys 0.016s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22326,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:24.940125  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling MajorDeltaCompactionOp(d25e7f2f38e24893aa598b72b9c43347): perf score=1.000000
I20260812 06:20:25.115024  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: MajorDeltaCompactionOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.175s	user 0.116s	sys 0.048s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672159,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":966,"lbm_read_time_us":12396,"lbm_reads_lt_1ms":463,"lbm_write_time_us":26669,"lbm_writes_lt_1ms":443,"mutex_wait_us":2,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:25.115686  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347): perf score=14.095187
I20260812 06:20:25.171404  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.055s	user 0.034s	sys 0.011s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21833,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:25.172029  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347): perf score=2.188937
I20260812 06:20:25.184689  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.012s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4502,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.185205  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling MajorDeltaCompactionOp(d25e7f2f38e24893aa598b72b9c43347): perf score=1.000000
I20260812 06:20:25.372301  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: MajorDeltaCompactionOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.187s	user 0.149s	sys 0.036s 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":396,"lbm_read_time_us":12410,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30192,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2500}
I20260812 06:20:25.372946  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347): perf score=14.095187
I20260812 06:20:25.419955  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.047s	user 0.023s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23163,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:25.420490  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347): perf score=2.188937
I20260812 06:20:25.440138  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.019s	user 0.013s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5206,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.440693  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling MajorDeltaCompactionOp(d25e7f2f38e24893aa598b72b9c43347): perf score=1.000000
I20260812 06:20:25.594360  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: MajorDeltaCompactionOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.153s	user 0.113s	sys 0.035s 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":522,"lbm_read_time_us":9912,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29752,"lbm_writes_lt_1ms":543,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":25856,"update_count":2500}
I20260812 06:20:25.594962  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347): perf score=11.118625
I20260812 06:20:25.629050  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.034s	user 0.021s	sys 0.011s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":14169,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:25.629912  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347): perf score=2.188937
I20260812 06:20:25.653460  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.023s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3774460,"delete_count":0,"lbm_write_time_us":5098,"lbm_writes_lt_1ms":95,"reinsert_count":0,"update_count":460}
I20260812 06:20:25.653918  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347): perf score=2.188937
I20260812 06:20:25.664743  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4020609,"delete_count":0,"lbm_write_time_us":4134,"lbm_writes_lt_1ms":101,"reinsert_count":0,"update_count":490}
I20260812 06:20:25.665254  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling MajorDeltaCompactionOp(d25e7f2f38e24893aa598b72b9c43347): perf score=1.000000
I20260812 06:20:25.826803  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: MajorDeltaCompactionOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.161s	user 0.122s	sys 0.027s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774805,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":848,"lbm_read_time_us":10425,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30114,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:20:25.827600  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347): perf score=14.095187
I20260812 06:20:25.883369  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.056s	user 0.033s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23793,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:25.884017  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347): perf score=2.188937
I20260812 06:20:25.898005  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.014s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5014,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.898499  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling FlushMRSOp(d25e7f2f38e24893aa598b72b9c43347): perf score=1.000000
I20260812 06:20:25.931689  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: FlushMRSOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.033s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":105,"dirs.run_cpu_time_us":287,"dirs.run_wall_time_us":1650,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1597,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:20:25.932488  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling LogGCOp(d25e7f2f38e24893aa598b72b9c43347): free 129320788 bytes of WAL
I20260812 06:20:25.932734  1262 log_reader.cc:385] T d25e7f2f38e24893aa598b72b9c43347: removed 13 log segments from log reader
I20260812 06:20:25.932796  1262 log.cc:1079] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/d25e7f2f38e24893aa598b72b9c43347/wal-000000027 (ops 129-133)
I20260812 06:20:25.932861  1262 log.cc:1079] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/d25e7f2f38e24893aa598b72b9c43347/wal-000000028 (ops 134-138)
I20260812 06:20:25.932906  1262 log.cc:1079] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/d25e7f2f38e24893aa598b72b9c43347/wal-000000029 (ops 139-143)
I20260812 06:20:25.932950  1262 log.cc:1079] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/d25e7f2f38e24893aa598b72b9c43347/wal-000000030 (ops 144-148)
I20260812 06:20:25.932996  1262 log.cc:1079] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/d25e7f2f38e24893aa598b72b9c43347/wal-000000031 (ops 149-152)
I20260812 06:20:25.933038  1262 log.cc:1079] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/d25e7f2f38e24893aa598b72b9c43347/wal-000000032 (ops 153-157)
I20260812 06:20:25.933084  1262 log.cc:1079] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/d25e7f2f38e24893aa598b72b9c43347/wal-000000033 (ops 158-162)
I20260812 06:20:25.933128  1262 log.cc:1079] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/d25e7f2f38e24893aa598b72b9c43347/wal-000000034 (ops 163-166)
I20260812 06:20:25.933205  1262 log.cc:1079] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/d25e7f2f38e24893aa598b72b9c43347/wal-000000035 (ops 167-171)
I20260812 06:20:25.933282  1262 log.cc:1079] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/d25e7f2f38e24893aa598b72b9c43347/wal-000000036 (ops 172-176)
I20260812 06:20:25.933344  1262 log.cc:1079] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/d25e7f2f38e24893aa598b72b9c43347/wal-000000037 (ops 177-181)
I20260812 06:20:25.933408  1262 log.cc:1079] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/d25e7f2f38e24893aa598b72b9c43347/wal-000000038 (ops 182-186)
I20260812 06:20:25.933449  1262 log.cc:1079] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/d25e7f2f38e24893aa598b72b9c43347/wal-000000039 (ops 187-191)
I20260812 06:20:25.961720  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: LogGCOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.029s	user 0.001s	sys 0.027s Metrics: {}
I20260812 06:20:25.962239  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347): perf score=6.157687
I20260812 06:20:25.999361  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.037s	user 0.016s	sys 0.016s Metrics: {"bytes_written":8205077,"delete_count":0,"lbm_write_time_us":11913,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:20:25.999994  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling MajorDeltaCompactionOp(d25e7f2f38e24893aa598b72b9c43347): perf score=1.000000
I20260812 06:20:26.108675  1148 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.885s	user 1.790s	sys 0.156s
I20260812 06:20:26.212880  1148 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.104s	user 0.002s	sys 0.000s
I20260812 06:20:26.213516  1148 tablet_server.cc:179] TabletServer@127.1.31.1:0 shutting down...
I20260812 06:20:26.216486  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: MajorDeltaCompactionOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.216s	user 0.131s	sys 0.083s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32979631,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":2523,"lbm_read_time_us":16703,"lbm_reads_lt_1ms":761,"lbm_write_time_us":36027,"lbm_writes_lt_1ms":743,"mutex_wait_us":2112,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":4864,"thread_start_us":163,"threads_started":1,"update_count":3500}
I20260812 06:20:26.217403  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling UndoDeltaBlockGCOp(d25e7f2f38e24893aa598b72b9c43347): 493 bytes on disk
I20260812 06:20:26.218209  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: UndoDeltaBlockGCOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":136,"lbm_reads_lt_1ms":4}
I20260812 06:20:26.218977  1328 maintenance_manager.cc:419] P 63045723b1624fa28dd2938f19d74c0e: Scheduling FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347): perf score=10.126437
I20260812 06:20:26.266378  1262 maintenance_manager.cc:643] P 63045723b1624fa28dd2938f19d74c0e: FlushDeltaMemStoresOp(d25e7f2f38e24893aa598b72b9c43347) complete. Timing: real 0.047s	user 0.020s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14698,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:26.267192  1148 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:26.267696  1148 tablet_replica.cc:333] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e: stopping tablet replica
I20260812 06:20:26.267961  1148 raft_consensus.cc:2243] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:26.268168  1148 raft_consensus.cc:2272] T d25e7f2f38e24893aa598b72b9c43347 P 63045723b1624fa28dd2938f19d74c0e [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:26.283368  1148 tablet_server.cc:196] TabletServer@127.1.31.1:0 shutdown complete.
I20260812 06:20:26.288563  1148 master.cc:562] Master@127.1.31.62:37501 shutting down...
I20260812 06:20:26.292258  1148 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 8d3c3523dc7c4d358779d218a88b7b8e [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:26.292472  1148 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 8d3c3523dc7c4d358779d218a88b7b8e [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:26.292536  1148 tablet_replica.cc:333] T 00000000000000000000000000000000 P 8d3c3523dc7c4d358779d218a88b7b8e: stopping tablet replica
I20260812 06:20:26.304998  1148 master.cc:584] Master@127.1.31.62:37501 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5458 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:20:26.403970  1148 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.1.31.62:37743
I20260812 06:20:26.404412  1148 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:20:26.406939  1148 server_base.cc:1061] running on GCE node
W20260812 06:20:26.406996  1360 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:20:26.407054  1363 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:20:26.407315  1361 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:20:26.407562  1148 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:26.407608  1148 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:20:26.407624  1148 hybrid_clock.cc:648] HybridClock initialized: now 1786515626407624 us; error 0 us; skew 500 ppm
I20260812 06:20:26.408505  1148 webserver.cc:533] Webserver started at http://127.1.31.62:38905/ using document root <none> and password file <none>
I20260812 06:20:26.408689  1148 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:26.408741  1148 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:26.408849  1148 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:26.409255  1148 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620920920-1148-0/minicluster-data/master-0-root/instance:
uuid: "c3989a3dbae3485291b430910fc75170"
format_stamp: "Formatted at 2026-08-12 06:20:26 on dist-test-slave-mvvj"
I20260812 06:20:26.410768  1148 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:20:26.411690  1369 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:20:26.412000  1148 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:26.412077  1148 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620920920-1148-0/minicluster-data/master-0-root
uuid: "c3989a3dbae3485291b430910fc75170"
format_stamp: "Formatted at 2026-08-12 06:20:26 on dist-test-slave-mvvj"
I20260812 06:20:26.412134  1148 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620920920-1148-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620920920-1148-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620920920-1148-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:20:26.435400  1148 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:26.435974  1148 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:26.440136  1148 rpc_server.cc:307] RPC server started. Bound to: 127.1.31.62:37743
I20260812 06:20:26.442267  1427 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.1.31.62:37743 every 8 connection(s)
I20260812 06:20:26.443527  1428 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:20:26.446002  1428 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P c3989a3dbae3485291b430910fc75170: Bootstrap starting.
I20260812 06:20:26.446803  1428 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P c3989a3dbae3485291b430910fc75170: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:26.447943  1428 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P c3989a3dbae3485291b430910fc75170: No bootstrap required, opened a new log
I20260812 06:20:26.448344  1428 raft_consensus.cc:359] T 00000000000000000000000000000000 P c3989a3dbae3485291b430910fc75170 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c3989a3dbae3485291b430910fc75170" member_type: VOTER }
I20260812 06:20:26.448431  1428 raft_consensus.cc:385] T 00000000000000000000000000000000 P c3989a3dbae3485291b430910fc75170 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:26.448493  1428 raft_consensus.cc:740] T 00000000000000000000000000000000 P c3989a3dbae3485291b430910fc75170 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: c3989a3dbae3485291b430910fc75170, State: Initialized, Role: FOLLOWER
I20260812 06:20:26.448649  1428 consensus_queue.cc:260] T 00000000000000000000000000000000 P c3989a3dbae3485291b430910fc75170 [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: "c3989a3dbae3485291b430910fc75170" member_type: VOTER }
I20260812 06:20:26.448729  1428 raft_consensus.cc:399] T 00000000000000000000000000000000 P c3989a3dbae3485291b430910fc75170 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:26.448786  1428 raft_consensus.cc:493] T 00000000000000000000000000000000 P c3989a3dbae3485291b430910fc75170 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:26.448843  1428 raft_consensus.cc:3060] T 00000000000000000000000000000000 P c3989a3dbae3485291b430910fc75170 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:26.449600  1428 raft_consensus.cc:515] T 00000000000000000000000000000000 P c3989a3dbae3485291b430910fc75170 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c3989a3dbae3485291b430910fc75170" member_type: VOTER }
I20260812 06:20:26.449746  1428 leader_election.cc:304] T 00000000000000000000000000000000 P c3989a3dbae3485291b430910fc75170 [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: c3989a3dbae3485291b430910fc75170; no voters: 
I20260812 06:20:26.449970  1428 leader_election.cc:290] T 00000000000000000000000000000000 P c3989a3dbae3485291b430910fc75170 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:26.450114  1432 raft_consensus.cc:2804] T 00000000000000000000000000000000 P c3989a3dbae3485291b430910fc75170 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:26.450363  1432 raft_consensus.cc:697] T 00000000000000000000000000000000 P c3989a3dbae3485291b430910fc75170 [term 1 LEADER]: Becoming Leader. State: Replica: c3989a3dbae3485291b430910fc75170, State: Running, Role: LEADER
I20260812 06:20:26.450423  1428 sys_catalog.cc:565] T 00000000000000000000000000000000 P c3989a3dbae3485291b430910fc75170 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:26.450538  1432 consensus_queue.cc:237] T 00000000000000000000000000000000 P c3989a3dbae3485291b430910fc75170 [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: "c3989a3dbae3485291b430910fc75170" member_type: VOTER }
I20260812 06:20:26.451002  1433 sys_catalog.cc:455] T 00000000000000000000000000000000 P c3989a3dbae3485291b430910fc75170 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "c3989a3dbae3485291b430910fc75170" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c3989a3dbae3485291b430910fc75170" member_type: VOTER } }
I20260812 06:20:26.451035  1435 sys_catalog.cc:455] T 00000000000000000000000000000000 P c3989a3dbae3485291b430910fc75170 [sys.catalog]: SysCatalogTable state changed. Reason: New leader c3989a3dbae3485291b430910fc75170. Latest consensus state: current_term: 1 leader_uuid: "c3989a3dbae3485291b430910fc75170" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c3989a3dbae3485291b430910fc75170" member_type: VOTER } }
I20260812 06:20:26.451107  1433 sys_catalog.cc:458] T 00000000000000000000000000000000 P c3989a3dbae3485291b430910fc75170 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:26.451123  1435 sys_catalog.cc:458] T 00000000000000000000000000000000 P c3989a3dbae3485291b430910fc75170 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:26.451390  1438 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:26.452299  1438 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:26.452675  1148 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:26.454097  1438 catalog_manager.cc:1383] Generated new cluster ID: 5a04ac7d744a47e491bdbd70dd5d080b
I20260812 06:20:26.454159  1438 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:26.463290  1438 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:26.463881  1438 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:26.481026  1438 catalog_manager.cc:6092] T 00000000000000000000000000000000 P c3989a3dbae3485291b430910fc75170: Generated new TSK 0
I20260812 06:20:26.481226  1438 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:26.484921  1148 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:26.486884  1452 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:20:26.487026  1455 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:20:26.487048  1453 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:20:26.487224  1148 server_base.cc:1061] running on GCE node
I20260812 06:20:26.487471  1148 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:26.487519  1148 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:20:26.487534  1148 hybrid_clock.cc:648] HybridClock initialized: now 1786515626487534 us; error 0 us; skew 500 ppm
I20260812 06:20:26.488476  1148 webserver.cc:533] Webserver started at http://127.1.31.1:40575/ using document root <none> and password file <none>
I20260812 06:20:26.488653  1148 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:26.488725  1148 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:26.488808  1148 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:26.489233  1148 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620920920-1148-0/minicluster-data/ts-0-root/instance:
uuid: "93f5b5efcde64540af27cfb81adb5c25"
format_stamp: "Formatted at 2026-08-12 06:20:26 on dist-test-slave-mvvj"
I20260812 06:20:26.490722  1148 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:26.491624  1460 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:20:26.491899  1148 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:26.491988  1148 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620920920-1148-0/minicluster-data/ts-0-root
uuid: "93f5b5efcde64540af27cfb81adb5c25"
format_stamp: "Formatted at 2026-08-12 06:20:26 on dist-test-slave-mvvj"
I20260812 06:20:26.492077  1148 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620920920-1148-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620920920-1148-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620920920-1148-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:20:26.512622  1148 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:26.513144  1148 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:26.513482  1148 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:26.513996  1148 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:26.514057  1148 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:26.514117  1148 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:26.514169  1148 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:26.518610  1148 rpc_server.cc:307] RPC server started. Bound to: 127.1.31.1:43685
I20260812 06:20:26.519677  1529 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.1.31.1:43685 every 8 connection(s)
I20260812 06:20:26.527179  1530 heartbeater.cc:344] Connected to a master server at 127.1.31.62:37743
I20260812 06:20:26.527274  1530 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:26.527505  1530 heartbeater.cc:507] Master 127.1.31.62:37743 requested a full tablet report, sending...
I20260812 06:20:26.528174  1386 ts_manager.cc:194] Registered new tserver with Master: 93f5b5efcde64540af27cfb81adb5c25 (127.1.31.1:43685)
I20260812 06:20:26.528501  1148 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.008911935s
I20260812 06:20:26.528972  1386 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:56752
I20260812 06:20:26.536125  1386 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:56760:
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:20:26.545214  1491 tablet_service.cc:1511] Processing CreateTablet for tablet 128e8ed6abe045c1aff766f10952b51c (DEFAULT_TABLE table=heavy-update-compaction-test [id=d7d034f9d7e84303883fe881401023cf]), partition=
I20260812 06:20:26.545513  1491 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 128e8ed6abe045c1aff766f10952b51c. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:26.547560  1545 tablet_bootstrap.cc:492] T 128e8ed6abe045c1aff766f10952b51c P 93f5b5efcde64540af27cfb81adb5c25: Bootstrap starting.
I20260812 06:20:26.548426  1545 tablet_bootstrap.cc:654] T 128e8ed6abe045c1aff766f10952b51c P 93f5b5efcde64540af27cfb81adb5c25: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:26.549504  1545 tablet_bootstrap.cc:492] T 128e8ed6abe045c1aff766f10952b51c P 93f5b5efcde64540af27cfb81adb5c25: No bootstrap required, opened a new log
I20260812 06:20:26.549610  1545 ts_tablet_manager.cc:1403] T 128e8ed6abe045c1aff766f10952b51c P 93f5b5efcde64540af27cfb81adb5c25: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:26.550177  1545 raft_consensus.cc:359] T 128e8ed6abe045c1aff766f10952b51c P 93f5b5efcde64540af27cfb81adb5c25 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "93f5b5efcde64540af27cfb81adb5c25" member_type: VOTER last_known_addr { host: "127.1.31.1" port: 43685 } }
I20260812 06:20:26.550362  1545 raft_consensus.cc:385] T 128e8ed6abe045c1aff766f10952b51c P 93f5b5efcde64540af27cfb81adb5c25 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:26.550417  1545 raft_consensus.cc:740] T 128e8ed6abe045c1aff766f10952b51c P 93f5b5efcde64540af27cfb81adb5c25 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 93f5b5efcde64540af27cfb81adb5c25, State: Initialized, Role: FOLLOWER
I20260812 06:20:26.550596  1545 consensus_queue.cc:260] T 128e8ed6abe045c1aff766f10952b51c P 93f5b5efcde64540af27cfb81adb5c25 [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: "93f5b5efcde64540af27cfb81adb5c25" member_type: VOTER last_known_addr { host: "127.1.31.1" port: 43685 } }
I20260812 06:20:26.550710  1545 raft_consensus.cc:399] T 128e8ed6abe045c1aff766f10952b51c P 93f5b5efcde64540af27cfb81adb5c25 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:26.550761  1545 raft_consensus.cc:493] T 128e8ed6abe045c1aff766f10952b51c P 93f5b5efcde64540af27cfb81adb5c25 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:26.550825  1545 raft_consensus.cc:3060] T 128e8ed6abe045c1aff766f10952b51c P 93f5b5efcde64540af27cfb81adb5c25 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:26.551710  1545 raft_consensus.cc:515] T 128e8ed6abe045c1aff766f10952b51c P 93f5b5efcde64540af27cfb81adb5c25 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "93f5b5efcde64540af27cfb81adb5c25" member_type: VOTER last_known_addr { host: "127.1.31.1" port: 43685 } }
I20260812 06:20:26.551898  1545 leader_election.cc:304] T 128e8ed6abe045c1aff766f10952b51c P 93f5b5efcde64540af27cfb81adb5c25 [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: 93f5b5efcde64540af27cfb81adb5c25; no voters: 
I20260812 06:20:26.552129  1545 leader_election.cc:290] T 128e8ed6abe045c1aff766f10952b51c P 93f5b5efcde64540af27cfb81adb5c25 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:26.552315  1547 raft_consensus.cc:2804] T 128e8ed6abe045c1aff766f10952b51c P 93f5b5efcde64540af27cfb81adb5c25 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:26.552592  1530 heartbeater.cc:499] Master 127.1.31.62:37743 was elected leader, sending a full tablet report...
I20260812 06:20:26.552625  1545 ts_tablet_manager.cc:1434] T 128e8ed6abe045c1aff766f10952b51c P 93f5b5efcde64540af27cfb81adb5c25: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:20:26.552606  1547 raft_consensus.cc:697] T 128e8ed6abe045c1aff766f10952b51c P 93f5b5efcde64540af27cfb81adb5c25 [term 1 LEADER]: Becoming Leader. State: Replica: 93f5b5efcde64540af27cfb81adb5c25, State: Running, Role: LEADER
I20260812 06:20:26.552924  1547 consensus_queue.cc:237] T 128e8ed6abe045c1aff766f10952b51c P 93f5b5efcde64540af27cfb81adb5c25 [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: "93f5b5efcde64540af27cfb81adb5c25" member_type: VOTER last_known_addr { host: "127.1.31.1" port: 43685 } }
I20260812 06:20:26.554347  1386 catalog_manager.cc:5719] T 128e8ed6abe045c1aff766f10952b51c P 93f5b5efcde64540af27cfb81adb5c25 reported cstate change: term changed from 0 to 1, leader changed from <none> to 93f5b5efcde64540af27cfb81adb5c25 (127.1.31.1). New cstate: current_term: 1 leader_uuid: "93f5b5efcde64540af27cfb81adb5c25" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "93f5b5efcde64540af27cfb81adb5c25" member_type: VOTER last_known_addr { host: "127.1.31.1" port: 43685 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:26.612586  1148 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.052s	user 0.018s	sys 0.004s
I20260812 06:20:26.770481  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling FlushMRSOp(128e8ed6abe045c1aff766f10952b51c): perf score=19.054940
I20260812 06:20:26.923161  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: FlushMRSOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.152s	user 0.121s	sys 0.027s Metrics: {"bytes_written":11897249,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":55,"dirs.run_cpu_time_us":230,"dirs.run_wall_time_us":871,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":35523,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":1450}
I20260812 06:20:26.924218  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling LogGCOp(128e8ed6abe045c1aff766f10952b51c): free 20743880 bytes of WAL
I20260812 06:20:26.924572  1465 log_reader.cc:385] T 128e8ed6abe045c1aff766f10952b51c: removed 2 log segments from log reader
I20260812 06:20:26.924659  1465 log.cc:1079] T 128e8ed6abe045c1aff766f10952b51c P 93f5b5efcde64540af27cfb81adb5c25: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/128e8ed6abe045c1aff766f10952b51c/wal-000000001 (ops 1-6)
I20260812 06:20:26.924708  1465 log.cc:1079] T 128e8ed6abe045c1aff766f10952b51c P 93f5b5efcde64540af27cfb81adb5c25: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/128e8ed6abe045c1aff766f10952b51c/wal-000000002 (ops 7-11)
I20260812 06:20:26.930620  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: LogGCOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.006s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:20:26.931180  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling UndoDeltaBlockGCOp(128e8ed6abe045c1aff766f10952b51c): 16821648 bytes on disk
I20260812 06:20:26.931932  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: UndoDeltaBlockGCOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.001s	user 0.001s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":135,"lbm_reads_lt_1ms":4}
I20260812 06:20:26.932547  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c): perf score=2.188937
I20260812 06:20:26.950783  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.018s	user 0.013s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6926,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.951506  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling MajorDeltaCompactionOp(128e8ed6abe045c1aff766f10952b51c): perf score=1.000000
I20260812 06:20:27.111852  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: MajorDeltaCompactionOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.160s	user 0.128s	sys 0.028s Metrics: {"cfile_cache_miss":422,"cfile_cache_miss_bytes":20303031,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":862,"lbm_read_time_us":11870,"lbm_reads_lt_1ms":454,"lbm_write_time_us":25859,"lbm_writes_lt_1ms":433,"mutex_wait_us":24,"peak_mem_usage":49238594,"reinsert_count":0,"spinlock_wait_cycles":16896,"thread_start_us":352,"threads_started":5,"update_count":1950}
I20260812 06:20:27.112550  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c): perf score=14.095187
I20260812 06:20:27.172113  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.059s	user 0.036s	sys 0.019s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23374,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:27.172689  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c): perf score=2.188937
I20260812 06:20:27.184732  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4236,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.185350  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling MajorDeltaCompactionOp(128e8ed6abe045c1aff766f10952b51c): perf score=1.000000
I20260812 06:20:27.362419  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: MajorDeltaCompactionOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.177s	user 0.100s	sys 0.072s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1076,"lbm_read_time_us":11839,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30269,"lbm_writes_lt_1ms":543,"mutex_wait_us":286,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13568,"update_count":2500}
I20260812 06:20:27.363219  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c): perf score=14.095187
I20260812 06:20:27.424505  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.061s	user 0.020s	sys 0.036s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20733,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:27.425118  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c): perf score=2.188937
I20260812 06:20:27.436177  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4267,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.436710  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling MajorDeltaCompactionOp(128e8ed6abe045c1aff766f10952b51c): perf score=1.000000
I20260812 06:20:27.638986  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: MajorDeltaCompactionOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.202s	user 0.155s	sys 0.044s 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":423,"lbm_read_time_us":14082,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30621,"lbm_writes_lt_1ms":543,"mutex_wait_us":62,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7552,"update_count":2500}
I20260812 06:20:27.639906  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c): perf score=11.118625
I20260812 06:20:27.679566  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.039s	user 0.023s	sys 0.013s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":16699,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:27.680246  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c): perf score=2.188937
I20260812 06:20:27.716931  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.036s	user 0.007s	sys 0.018s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5544,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:27.717604  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c): perf score=2.188937
I20260812 06:20:27.728844  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.011s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4192,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.729449  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling MajorDeltaCompactionOp(128e8ed6abe045c1aff766f10952b51c): perf score=1.000000
I20260812 06:20:27.927000  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: MajorDeltaCompactionOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.197s	user 0.103s	sys 0.087s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815794,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":319,"lbm_read_time_us":13539,"lbm_reads_lt_1ms":573,"lbm_write_time_us":28611,"lbm_writes_lt_1ms":543,"mutex_wait_us":45,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5632,"update_count":2500}
I20260812 06:20:27.927810  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c): perf score=14.095187
I20260812 06:20:27.979709  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.052s	user 0.028s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21351,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:27.980283  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c): perf score=2.188937
I20260812 06:20:27.991376  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.011s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4130,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.991974  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling MajorDeltaCompactionOp(128e8ed6abe045c1aff766f10952b51c): perf score=1.000000
I20260812 06:20:28.181561  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: MajorDeltaCompactionOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.189s	user 0.113s	sys 0.069s 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":371,"lbm_read_time_us":10396,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28709,"lbm_writes_lt_1ms":543,"mutex_wait_us":70,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4864,"update_count":2500}
I20260812 06:20:28.182245  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c): perf score=14.095187
I20260812 06:20:28.236243  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.054s	user 0.023s	sys 0.021s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":19411,"lbm_writes_lt_1ms":403,"mutex_wait_us":2,"reinsert_count":0,"update_count":2000}
I20260812 06:20:28.236740  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c): perf score=2.188937
I20260812 06:20:28.248332  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4254,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.248991  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling FlushMRSOp(128e8ed6abe045c1aff766f10952b51c): perf score=1.000000
I20260812 06:20:28.281502  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: FlushMRSOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.032s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":77,"dirs.run_cpu_time_us":262,"dirs.run_wall_time_us":1584,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1530,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:28.282151  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling LogGCOp(128e8ed6abe045c1aff766f10952b51c): free 115943176 bytes of WAL
I20260812 06:20:28.282444  1465 log_reader.cc:385] T 128e8ed6abe045c1aff766f10952b51c: removed 11 log segments from log reader
I20260812 06:20:28.282514  1465 log.cc:1079] T 128e8ed6abe045c1aff766f10952b51c P 93f5b5efcde64540af27cfb81adb5c25: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/128e8ed6abe045c1aff766f10952b51c/wal-000000003 (ops 12-16)
I20260812 06:20:28.282557  1465 log.cc:1079] T 128e8ed6abe045c1aff766f10952b51c P 93f5b5efcde64540af27cfb81adb5c25: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/128e8ed6abe045c1aff766f10952b51c/wal-000000004 (ops 17-21)
I20260812 06:20:28.282583  1465 log.cc:1079] T 128e8ed6abe045c1aff766f10952b51c P 93f5b5efcde64540af27cfb81adb5c25: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/128e8ed6abe045c1aff766f10952b51c/wal-000000005 (ops 22-26)
I20260812 06:20:28.282605  1465 log.cc:1079] T 128e8ed6abe045c1aff766f10952b51c P 93f5b5efcde64540af27cfb81adb5c25: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/128e8ed6abe045c1aff766f10952b51c/wal-000000006 (ops 27-31)
I20260812 06:20:28.282640  1465 log.cc:1079] T 128e8ed6abe045c1aff766f10952b51c P 93f5b5efcde64540af27cfb81adb5c25: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/128e8ed6abe045c1aff766f10952b51c/wal-000000007 (ops 32-36)
I20260812 06:20:28.282662  1465 log.cc:1079] T 128e8ed6abe045c1aff766f10952b51c P 93f5b5efcde64540af27cfb81adb5c25: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/128e8ed6abe045c1aff766f10952b51c/wal-000000008 (ops 37-41)
I20260812 06:20:28.282696  1465 log.cc:1079] T 128e8ed6abe045c1aff766f10952b51c P 93f5b5efcde64540af27cfb81adb5c25: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/128e8ed6abe045c1aff766f10952b51c/wal-000000009 (ops 42-46)
I20260812 06:20:28.282729  1465 log.cc:1079] T 128e8ed6abe045c1aff766f10952b51c P 93f5b5efcde64540af27cfb81adb5c25: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/128e8ed6abe045c1aff766f10952b51c/wal-000000010 (ops 47-51)
I20260812 06:20:28.282752  1465 log.cc:1079] T 128e8ed6abe045c1aff766f10952b51c P 93f5b5efcde64540af27cfb81adb5c25: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/128e8ed6abe045c1aff766f10952b51c/wal-000000011 (ops 52-56)
I20260812 06:20:28.282780  1465 log.cc:1079] T 128e8ed6abe045c1aff766f10952b51c P 93f5b5efcde64540af27cfb81adb5c25: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/128e8ed6abe045c1aff766f10952b51c/wal-000000012 (ops 57-61)
I20260812 06:20:28.282809  1465 log.cc:1079] T 128e8ed6abe045c1aff766f10952b51c P 93f5b5efcde64540af27cfb81adb5c25: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/128e8ed6abe045c1aff766f10952b51c/wal-000000013 (ops 62-66)
I20260812 06:20:28.311359  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: LogGCOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.029s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:20:28.317276  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c): perf score=2.188937
I20260812 06:20:28.340546  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.023s	user 0.011s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6445,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.341037  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling UndoDeltaBlockGCOp(128e8ed6abe045c1aff766f10952b51c): 447 bytes on disk
I20260812 06:20:28.341434  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: UndoDeltaBlockGCOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:20:28.341876  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c): perf score=2.188937
I20260812 06:20:28.352461  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4049,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.352890  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling MajorDeltaCompactionOp(128e8ed6abe045c1aff766f10952b51c): perf score=1.000000
I20260812 06:20:28.599859  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: MajorDeltaCompactionOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.247s	user 0.150s	sys 0.088s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020741,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":604,"lbm_read_time_us":16048,"lbm_reads_lt_1ms":774,"lbm_write_time_us":38729,"lbm_writes_lt_1ms":743,"mutex_wait_us":47,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":18944,"thread_start_us":88,"threads_started":1,"update_count":3500}
I20260812 06:20:28.600654  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c): perf score=18.063937
I20260812 06:20:28.671801  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.071s	user 0.043s	sys 0.019s Metrics: {"bytes_written":20512313,"delete_count":0,"lbm_write_time_us":29844,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:20:28.672438  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c): perf score=2.188937
I20260812 06:20:28.684114  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4027,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.684899  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling MajorDeltaCompactionOp(128e8ed6abe045c1aff766f10952b51c): perf score=1.000000
I20260812 06:20:28.918706  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: MajorDeltaCompactionOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.234s	user 0.165s	sys 0.068s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918095,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":312,"lbm_read_time_us":13538,"lbm_reads_lt_1ms":672,"lbm_write_time_us":42463,"lbm_writes_lt_1ms":643,"mutex_wait_us":58,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":40704,"update_count":3000}
I20260812 06:20:28.919310  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c): perf score=14.095187
I20260812 06:20:28.977720  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.058s	user 0.014s	sys 0.032s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21631,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:20:28.978381  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c): perf score=2.188937
I20260812 06:20:28.989277  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4248,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.989766  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling MajorDeltaCompactionOp(128e8ed6abe045c1aff766f10952b51c): perf score=1.000000
I20260812 06:20:29.166002  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: MajorDeltaCompactionOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.176s	user 0.112s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":677,"lbm_read_time_us":11997,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28024,"lbm_writes_lt_1ms":543,"mutex_wait_us":202,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5120,"update_count":2500}
I20260812 06:20:29.166754  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c): perf score=14.095187
I20260812 06:20:29.217458  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.051s	user 0.029s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19550,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:29.217976  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c): perf score=2.188937
I20260812 06:20:29.229600  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4649,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.230234  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling MajorDeltaCompactionOp(128e8ed6abe045c1aff766f10952b51c): perf score=1.000000
I20260812 06:20:29.405561  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: MajorDeltaCompactionOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.175s	user 0.120s	sys 0.054s 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":927,"lbm_read_time_us":11580,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29141,"lbm_writes_lt_1ms":543,"mutex_wait_us":241,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":23040,"update_count":2500}
I20260812 06:20:29.406250  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c): perf score=14.095187
I20260812 06:20:29.470930  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.064s	user 0.017s	sys 0.044s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21837,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:29.471593  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c): perf score=2.188937
I20260812 06:20:29.483309  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.011s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4619,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.483923  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling MajorDeltaCompactionOp(128e8ed6abe045c1aff766f10952b51c): perf score=1.000000
I20260812 06:20:29.673287  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: MajorDeltaCompactionOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.189s	user 0.136s	sys 0.053s 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":417,"lbm_read_time_us":13389,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31299,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15488,"update_count":2500}
I20260812 06:20:29.673990  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c): perf score=14.095187
I20260812 06:20:29.735024  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.061s	user 0.035s	sys 0.019s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":21179,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:20:29.735682  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c): perf score=2.188937
I20260812 06:20:29.747107  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4244,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.747579  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling FlushMRSOp(128e8ed6abe045c1aff766f10952b51c): perf score=1.000000
I20260812 06:20:29.779527  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: FlushMRSOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.032s	user 0.024s	sys 0.004s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":86,"dirs.run_cpu_time_us":236,"dirs.run_wall_time_us":1493,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1448,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28,"spinlock_wait_cycles":3968}
I20260812 06:20:29.780239  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling MajorDeltaCompactionOp(128e8ed6abe045c1aff766f10952b51c): perf score=1.000000
I20260812 06:20:29.955041  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: MajorDeltaCompactionOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.175s	user 0.101s	sys 0.073s 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":403,"lbm_read_time_us":11335,"lbm_reads_lt_1ms":564,"lbm_write_time_us":27805,"lbm_writes_lt_1ms":543,"mutex_wait_us":87,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7168,"update_count":2500}
I20260812 06:20:29.958940  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling LogGCOp(128e8ed6abe045c1aff766f10952b51c): free 121006381 bytes of WAL
I20260812 06:20:29.959249  1465 log_reader.cc:385] T 128e8ed6abe045c1aff766f10952b51c: removed 12 log segments from log reader
I20260812 06:20:29.959331  1465 log.cc:1079] T 128e8ed6abe045c1aff766f10952b51c P 93f5b5efcde64540af27cfb81adb5c25: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/128e8ed6abe045c1aff766f10952b51c/wal-000000014 (ops 67-71)
I20260812 06:20:29.959424  1465 log.cc:1079] T 128e8ed6abe045c1aff766f10952b51c P 93f5b5efcde64540af27cfb81adb5c25: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/128e8ed6abe045c1aff766f10952b51c/wal-000000015 (ops 72-76)
I20260812 06:20:29.959493  1465 log.cc:1079] T 128e8ed6abe045c1aff766f10952b51c P 93f5b5efcde64540af27cfb81adb5c25: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/128e8ed6abe045c1aff766f10952b51c/wal-000000016 (ops 77-81)
I20260812 06:20:29.959578  1465 log.cc:1079] T 128e8ed6abe045c1aff766f10952b51c P 93f5b5efcde64540af27cfb81adb5c25: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/128e8ed6abe045c1aff766f10952b51c/wal-000000017 (ops 82-86)
I20260812 06:20:29.959649  1465 log.cc:1079] T 128e8ed6abe045c1aff766f10952b51c P 93f5b5efcde64540af27cfb81adb5c25: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/128e8ed6abe045c1aff766f10952b51c/wal-000000018 (ops 87-91)
I20260812 06:20:29.959730  1465 log.cc:1079] T 128e8ed6abe045c1aff766f10952b51c P 93f5b5efcde64540af27cfb81adb5c25: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/128e8ed6abe045c1aff766f10952b51c/wal-000000019 (ops 92-96)
I20260812 06:20:29.959775  1465 log.cc:1079] T 128e8ed6abe045c1aff766f10952b51c P 93f5b5efcde64540af27cfb81adb5c25: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/128e8ed6abe045c1aff766f10952b51c/wal-000000020 (ops 97-101)
I20260812 06:20:29.959879  1465 log.cc:1079] T 128e8ed6abe045c1aff766f10952b51c P 93f5b5efcde64540af27cfb81adb5c25: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/128e8ed6abe045c1aff766f10952b51c/wal-000000021 (ops 102-106)
I20260812 06:20:29.959954  1465 log.cc:1079] T 128e8ed6abe045c1aff766f10952b51c P 93f5b5efcde64540af27cfb81adb5c25: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/128e8ed6abe045c1aff766f10952b51c/wal-000000022 (ops 107-111)
I20260812 06:20:29.959998  1465 log.cc:1079] T 128e8ed6abe045c1aff766f10952b51c P 93f5b5efcde64540af27cfb81adb5c25: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/128e8ed6abe045c1aff766f10952b51c/wal-000000023 (ops 112-116)
I20260812 06:20:29.960026  1465 log.cc:1079] T 128e8ed6abe045c1aff766f10952b51c P 93f5b5efcde64540af27cfb81adb5c25: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/128e8ed6abe045c1aff766f10952b51c/wal-000000024 (ops 117-120)
I20260812 06:20:29.960050  1465 log.cc:1079] T 128e8ed6abe045c1aff766f10952b51c P 93f5b5efcde64540af27cfb81adb5c25: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/128e8ed6abe045c1aff766f10952b51c/wal-000000025 (ops 121-125)
I20260812 06:20:29.989485  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: LogGCOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.030s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:20:29.989949  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling UndoDeltaBlockGCOp(128e8ed6abe045c1aff766f10952b51c): 447 bytes on disk
I20260812 06:20:29.990521  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: UndoDeltaBlockGCOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4}
I20260812 06:20:29.991113  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c): perf score=17.071750
I20260812 06:20:30.064195  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.073s	user 0.047s	sys 0.023s Metrics: {"bytes_written":19281595,"delete_count":0,"lbm_write_time_us":26976,"lbm_writes_lt_1ms":473,"reinsert_count":0,"update_count":2350}
I20260812 06:20:30.064806  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c): perf score=4.173312
I20260812 06:20:30.079387  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":5333390,"delete_count":0,"lbm_write_time_us":5844,"lbm_writes_lt_1ms":133,"reinsert_count":0,"update_count":650}
I20260812 06:20:30.079962  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling MajorDeltaCompactionOp(128e8ed6abe045c1aff766f10952b51c): perf score=1.000000
I20260812 06:20:30.293572  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: MajorDeltaCompactionOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.213s	user 0.159s	sys 0.052s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918102,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":301,"lbm_read_time_us":14880,"lbm_reads_lt_1ms":672,"lbm_write_time_us":36542,"lbm_writes_lt_1ms":643,"mutex_wait_us":46,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":3000}
I20260812 06:20:30.294379  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c): perf score=15.087375
I20260812 06:20:30.350636  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.056s	user 0.043s	sys 0.011s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":20890,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:20:30.351225  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c): perf score=2.188937
I20260812 06:20:30.363972  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.013s	user 0.008s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4378,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:30.364483  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c): perf score=2.188937
I20260812 06:20:30.379670  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5844,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:30.380308  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling MajorDeltaCompactionOp(128e8ed6abe045c1aff766f10952b51c): perf score=1.000000
I20260812 06:20:30.619354  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: MajorDeltaCompactionOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.239s	user 0.142s	sys 0.085s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918202,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":452,"lbm_read_time_us":14935,"lbm_reads_lt_1ms":673,"lbm_write_time_us":37002,"lbm_writes_lt_1ms":643,"mutex_wait_us":89,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:20:30.620321  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c): perf score=18.063937
I20260812 06:20:30.690495  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.070s	user 0.023s	sys 0.033s Metrics: {"bytes_written":20512314,"delete_count":0,"lbm_write_time_us":27042,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:30.691100  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c): perf score=2.188937
I20260812 06:20:30.704066  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.013s	user 0.009s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4391,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:30.704809  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling MajorDeltaCompactionOp(128e8ed6abe045c1aff766f10952b51c): perf score=1.000000
I20260812 06:20:30.924270  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: MajorDeltaCompactionOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.219s	user 0.155s	sys 0.053s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918096,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":902,"lbm_read_time_us":13837,"lbm_reads_lt_1ms":672,"lbm_write_time_us":36561,"lbm_writes_lt_1ms":643,"mutex_wait_us":303,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7552,"update_count":3000}
I20260812 06:20:30.925139  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c): perf score=18.063937
I20260812 06:20:30.997335  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.072s	user 0.052s	sys 0.009s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":28263,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:30.997884  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c): perf score=2.188937
I20260812 06:20:31.008477  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4043,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:31.008963  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling MajorDeltaCompactionOp(128e8ed6abe045c1aff766f10952b51c): perf score=1.000000
I20260812 06:20:31.221964  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: MajorDeltaCompactionOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.213s	user 0.161s	sys 0.051s 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":874,"lbm_read_time_us":14419,"lbm_reads_lt_1ms":672,"lbm_write_time_us":37255,"lbm_writes_lt_1ms":643,"mutex_wait_us":361,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:20:31.222760  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c): perf score=14.095187
I20260812 06:20:31.276260  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.053s	user 0.017s	sys 0.035s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23959,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:31.276928  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c): perf score=2.188937
I20260812 06:20:31.296607  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.019s	user 0.010s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7488,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:31.297271  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling FlushMRSOp(128e8ed6abe045c1aff766f10952b51c): perf score=1.000000
I20260812 06:20:31.325445  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: FlushMRSOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.028s	user 0.022s	sys 0.004s Metrics: {"bytes_written":1193505,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":246,"dirs.run_wall_time_us":1274,"drs_written":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1734,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:31.326287  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling LogGCOp(128e8ed6abe045c1aff766f10952b51c): free 112239546 bytes of WAL
I20260812 06:20:31.326646  1465 log_reader.cc:385] T 128e8ed6abe045c1aff766f10952b51c: removed 11 log segments from log reader
I20260812 06:20:31.326709  1465 log.cc:1079] T 128e8ed6abe045c1aff766f10952b51c P 93f5b5efcde64540af27cfb81adb5c25: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/128e8ed6abe045c1aff766f10952b51c/wal-000000026 (ops 126-130)
I20260812 06:20:31.326751  1465 log.cc:1079] T 128e8ed6abe045c1aff766f10952b51c P 93f5b5efcde64540af27cfb81adb5c25: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/128e8ed6abe045c1aff766f10952b51c/wal-000000027 (ops 131-135)
I20260812 06:20:31.326783  1465 log.cc:1079] T 128e8ed6abe045c1aff766f10952b51c P 93f5b5efcde64540af27cfb81adb5c25: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/128e8ed6abe045c1aff766f10952b51c/wal-000000028 (ops 136-140)
I20260812 06:20:31.326807  1465 log.cc:1079] T 128e8ed6abe045c1aff766f10952b51c P 93f5b5efcde64540af27cfb81adb5c25: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/128e8ed6abe045c1aff766f10952b51c/wal-000000029 (ops 141-145)
I20260812 06:20:31.326841  1465 log.cc:1079] T 128e8ed6abe045c1aff766f10952b51c P 93f5b5efcde64540af27cfb81adb5c25: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/128e8ed6abe045c1aff766f10952b51c/wal-000000030 (ops 146-150)
I20260812 06:20:31.326879  1465 log.cc:1079] T 128e8ed6abe045c1aff766f10952b51c P 93f5b5efcde64540af27cfb81adb5c25: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/128e8ed6abe045c1aff766f10952b51c/wal-000000031 (ops 151-155)
I20260812 06:20:31.326903  1465 log.cc:1079] T 128e8ed6abe045c1aff766f10952b51c P 93f5b5efcde64540af27cfb81adb5c25: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/128e8ed6abe045c1aff766f10952b51c/wal-000000032 (ops 156-160)
I20260812 06:20:31.326932  1465 log.cc:1079] T 128e8ed6abe045c1aff766f10952b51c P 93f5b5efcde64540af27cfb81adb5c25: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/128e8ed6abe045c1aff766f10952b51c/wal-000000033 (ops 161-164)
I20260812 06:20:31.326972  1465 log.cc:1079] T 128e8ed6abe045c1aff766f10952b51c P 93f5b5efcde64540af27cfb81adb5c25: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/128e8ed6abe045c1aff766f10952b51c/wal-000000034 (ops 165-169)
I20260812 06:20:31.327003  1465 log.cc:1079] T 128e8ed6abe045c1aff766f10952b51c P 93f5b5efcde64540af27cfb81adb5c25: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/128e8ed6abe045c1aff766f10952b51c/wal-000000035 (ops 170-174)
I20260812 06:20:31.327037  1465 log.cc:1079] T 128e8ed6abe045c1aff766f10952b51c P 93f5b5efcde64540af27cfb81adb5c25: Deleting log segment in path: /tmp/dist-test-task0dIIy6/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515620920920-1148-0/minicluster-data/ts-0-root/wals/128e8ed6abe045c1aff766f10952b51c/wal-000000036 (ops 175-179)
I20260812 06:20:31.354775  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: LogGCOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.028s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:20:31.355211  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c): perf score=2.188937
I20260812 06:20:31.378235  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.023s	user 0.000s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4502,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:31.378724  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling UndoDeltaBlockGCOp(128e8ed6abe045c1aff766f10952b51c): 463 bytes on disk
I20260812 06:20:31.379158  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: UndoDeltaBlockGCOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4}
I20260812 06:20:31.379688  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c): perf score=2.188937
I20260812 06:20:31.390707  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4195,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:31.391525  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling MajorDeltaCompactionOp(128e8ed6abe045c1aff766f10952b51c): perf score=1.000000
I20260812 06:20:31.632753  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: MajorDeltaCompactionOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.241s	user 0.161s	sys 0.076s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020744,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":5559,"lbm_read_time_us":16165,"lbm_reads_lt_1ms":774,"lbm_write_time_us":43254,"lbm_writes_lt_1ms":743,"mutex_wait_us":1699,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":17408,"thread_start_us":93,"threads_started":1,"update_count":3500}
I20260812 06:20:31.633450  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c): perf score=18.063937
I20260812 06:20:31.702533  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.069s	user 0.050s	sys 0.016s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":31526,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:31.703014  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c): perf score=2.188937
I20260812 06:20:31.715794  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: FlushDeltaMemStoresOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.013s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4724,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:31.716363  1531 maintenance_manager.cc:419] P 93f5b5efcde64540af27cfb81adb5c25: Scheduling MajorDeltaCompactionOp(128e8ed6abe045c1aff766f10952b51c): perf score=1.000000
I20260812 06:20:31.787144  1148 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.174s	user 1.903s	sys 0.225s
I20260812 06:20:31.848816  1148 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.061s	user 0.002s	sys 0.000s
I20260812 06:20:31.849342  1148 tablet_server.cc:179] TabletServer@127.1.31.1:0 shutting down...
I20260812 06:20:31.877588  1465 maintenance_manager.cc:643] P 93f5b5efcde64540af27cfb81adb5c25: MajorDeltaCompactionOp(128e8ed6abe045c1aff766f10952b51c) complete. Timing: real 0.161s	user 0.128s	sys 0.033s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918097,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":374,"lbm_read_time_us":11826,"lbm_reads_lt_1ms":668,"lbm_write_time_us":31092,"lbm_writes_lt_1ms":643,"mutex_wait_us":46,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":16256,"update_count":3000}
I20260812 06:20:31.878357  1148 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:31.878671  1148 tablet_replica.cc:333] T 128e8ed6abe045c1aff766f10952b51c P 93f5b5efcde64540af27cfb81adb5c25: stopping tablet replica
I20260812 06:20:31.878960  1148 raft_consensus.cc:2243] T 128e8ed6abe045c1aff766f10952b51c P 93f5b5efcde64540af27cfb81adb5c25 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:31.879187  1148 raft_consensus.cc:2272] T 128e8ed6abe045c1aff766f10952b51c P 93f5b5efcde64540af27cfb81adb5c25 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:31.885113  1148 tablet_server.cc:196] TabletServer@127.1.31.1:0 shutdown complete.
I20260812 06:20:31.935783  1148 master.cc:562] Master@127.1.31.62:37743 shutting down...
I20260812 06:20:31.939298  1148 raft_consensus.cc:2243] T 00000000000000000000000000000000 P c3989a3dbae3485291b430910fc75170 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:31.939487  1148 raft_consensus.cc:2272] T 00000000000000000000000000000000 P c3989a3dbae3485291b430910fc75170 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:31.939538  1148 tablet_replica.cc:333] T 00000000000000000000000000000000 P c3989a3dbae3485291b430910fc75170: stopping tablet replica
I20260812 06:20:31.952176  1148 master.cc:584] Master@127.1.31.62:37743 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5650 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11110 ms total)

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