[==========] 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:16:31.277841 30248 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.29.138.62:43079
I20260812 06:16:31.279234 30248 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:16:31.279942 30248 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:31.286299 30253 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:16:31.286299 30254 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:16:31.286427 30248 server_base.cc:1061] running on GCE node
W20260812 06:16:31.286631 30256 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:16:31.287189 30248 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:31.287282 30248 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:16:31.287314 30248 hybrid_clock.cc:648] HybridClock initialized: now 1786515391287313 us; error 0 us; skew 500 ppm
I20260812 06:16:31.289172 30248 webserver.cc:533] Webserver started at http://127.29.138.62:38449/ using document root <none> and password file <none>
I20260812 06:16:31.289706 30248 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:31.289762 30248 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:31.289958 30248 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:31.291711 30248 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515391260141-30248-0/minicluster-data/master-0-root/instance:
uuid: "f252b3b855c4473db499b668c5c8053f"
format_stamp: "Formatted at 2026-08-12 06:16:31 on dist-test-slave-1jjb"
I20260812 06:16:31.295769 30248 fs_manager.cc:696] Time spent creating directory manager: real 0.004s	user 0.002s	sys 0.000s
I20260812 06:16:31.298246 30262 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:16:31.299420 30248 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:16:31.299606 30248 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515391260141-30248-0/minicluster-data/master-0-root
uuid: "f252b3b855c4473db499b668c5c8053f"
format_stamp: "Formatted at 2026-08-12 06:16:31 on dist-test-slave-1jjb"
I20260812 06:16:31.299731 30248 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515391260141-30248-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515391260141-30248-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515391260141-30248-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:16:31.312430 30248 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:31.313196 30248 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:16:31.313403 30248 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:31.321904 30248 rpc_server.cc:307] RPC server started. Bound to: 127.29.138.62:43079
I20260812 06:16:31.321909 30325 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.29.138.62:43079 every 8 connection(s)
I20260812 06:16:31.324414 30326 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:16:31.330359 30326 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P f252b3b855c4473db499b668c5c8053f: Bootstrap starting.
I20260812 06:16:31.333007 30326 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P f252b3b855c4473db499b668c5c8053f: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:31.334074 30326 log.cc:826] T 00000000000000000000000000000000 P f252b3b855c4473db499b668c5c8053f: Log is configured to *not* fsync() on all Append() calls
I20260812 06:16:31.336045 30326 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P f252b3b855c4473db499b668c5c8053f: No bootstrap required, opened a new log
I20260812 06:16:31.339156 30326 raft_consensus.cc:359] T 00000000000000000000000000000000 P f252b3b855c4473db499b668c5c8053f [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f252b3b855c4473db499b668c5c8053f" member_type: VOTER }
I20260812 06:16:31.339347 30326 raft_consensus.cc:385] T 00000000000000000000000000000000 P f252b3b855c4473db499b668c5c8053f [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:31.339452 30326 raft_consensus.cc:740] T 00000000000000000000000000000000 P f252b3b855c4473db499b668c5c8053f [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: f252b3b855c4473db499b668c5c8053f, State: Initialized, Role: FOLLOWER
I20260812 06:16:31.340219 30326 consensus_queue.cc:260] T 00000000000000000000000000000000 P f252b3b855c4473db499b668c5c8053f [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: "f252b3b855c4473db499b668c5c8053f" member_type: VOTER }
I20260812 06:16:31.340416 30326 raft_consensus.cc:399] T 00000000000000000000000000000000 P f252b3b855c4473db499b668c5c8053f [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:31.340526 30326 raft_consensus.cc:493] T 00000000000000000000000000000000 P f252b3b855c4473db499b668c5c8053f [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:31.340689 30326 raft_consensus.cc:3060] T 00000000000000000000000000000000 P f252b3b855c4473db499b668c5c8053f [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:31.341604 30326 raft_consensus.cc:515] T 00000000000000000000000000000000 P f252b3b855c4473db499b668c5c8053f [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f252b3b855c4473db499b668c5c8053f" member_type: VOTER }
I20260812 06:16:31.342106 30326 leader_election.cc:304] T 00000000000000000000000000000000 P f252b3b855c4473db499b668c5c8053f [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: f252b3b855c4473db499b668c5c8053f; no voters: 
I20260812 06:16:31.342506 30326 leader_election.cc:290] T 00000000000000000000000000000000 P f252b3b855c4473db499b668c5c8053f [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:31.342656 30330 raft_consensus.cc:2804] T 00000000000000000000000000000000 P f252b3b855c4473db499b668c5c8053f [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:31.342929 30330 raft_consensus.cc:697] T 00000000000000000000000000000000 P f252b3b855c4473db499b668c5c8053f [term 1 LEADER]: Becoming Leader. State: Replica: f252b3b855c4473db499b668c5c8053f, State: Running, Role: LEADER
I20260812 06:16:31.343374 30330 consensus_queue.cc:237] T 00000000000000000000000000000000 P f252b3b855c4473db499b668c5c8053f [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: "f252b3b855c4473db499b668c5c8053f" member_type: VOTER }
I20260812 06:16:31.343674 30326 sys_catalog.cc:565] T 00000000000000000000000000000000 P f252b3b855c4473db499b668c5c8053f [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:31.345420 30331 sys_catalog.cc:455] T 00000000000000000000000000000000 P f252b3b855c4473db499b668c5c8053f [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "f252b3b855c4473db499b668c5c8053f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f252b3b855c4473db499b668c5c8053f" member_type: VOTER } }
I20260812 06:16:31.345559 30331 sys_catalog.cc:458] T 00000000000000000000000000000000 P f252b3b855c4473db499b668c5c8053f [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:31.345865 30332 sys_catalog.cc:455] T 00000000000000000000000000000000 P f252b3b855c4473db499b668c5c8053f [sys.catalog]: SysCatalogTable state changed. Reason: New leader f252b3b855c4473db499b668c5c8053f. Latest consensus state: current_term: 1 leader_uuid: "f252b3b855c4473db499b668c5c8053f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f252b3b855c4473db499b668c5c8053f" member_type: VOTER } }
I20260812 06:16:31.345953 30332 sys_catalog.cc:458] T 00000000000000000000000000000000 P f252b3b855c4473db499b668c5c8053f [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:31.346307 30248 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:16:31.346339 30342 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:31.348726 30342 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:31.353596 30342 catalog_manager.cc:1383] Generated new cluster ID: b522d37219064d8f833b6f7df995c284
I20260812 06:16:31.353685 30342 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:31.372687 30342 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:31.373970 30342 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:31.382268 30342 catalog_manager.cc:6092] T 00000000000000000000000000000000 P f252b3b855c4473db499b668c5c8053f: Generated new TSK 0
I20260812 06:16:31.383122 30342 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:31.411211 30248 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:31.413905 30354 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:16:31.414044 30357 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:16:31.414198 30248 server_base.cc:1061] running on GCE node
W20260812 06:16:31.414183 30355 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:16:31.414491 30248 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:31.414558 30248 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:16:31.414585 30248 hybrid_clock.cc:648] HybridClock initialized: now 1786515391414584 us; error 0 us; skew 500 ppm
I20260812 06:16:31.415570 30248 webserver.cc:533] Webserver started at http://127.29.138.1:42225/ using document root <none> and password file <none>
I20260812 06:16:31.415758 30248 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:31.415831 30248 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:31.415910 30248 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:31.416370 30248 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515391260141-30248-0/minicluster-data/ts-0-root/instance:
uuid: "747c3382653b46cf8173285cb8641d8d"
format_stamp: "Formatted at 2026-08-12 06:16:31 on dist-test-slave-1jjb"
I20260812 06:16:31.418015 30248 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:16:31.419024 30362 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:16:31.419278 30248 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:31.419348 30248 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515391260141-30248-0/minicluster-data/ts-0-root
uuid: "747c3382653b46cf8173285cb8641d8d"
format_stamp: "Formatted at 2026-08-12 06:16:31 on dist-test-slave-1jjb"
I20260812 06:16:31.419433 30248 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515391260141-30248-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515391260141-30248-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515391260141-30248-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:16:31.428823 30248 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:31.429270 30248 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:31.429775 30248 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:31.430660 30248 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:31.430716 30248 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:31.430791 30248 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:31.430827 30248 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:31.437759 30248 rpc_server.cc:307] RPC server started. Bound to: 127.29.138.1:35043
I20260812 06:16:31.437988 30433 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.29.138.1:35043 every 8 connection(s)
I20260812 06:16:31.448427 30434 heartbeater.cc:344] Connected to a master server at 127.29.138.62:43079
I20260812 06:16:31.448702 30434 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:31.449245 30434 heartbeater.cc:507] Master 127.29.138.62:43079 requested a full tablet report, sending...
I20260812 06:16:31.450817 30281 ts_manager.cc:194] Registered new tserver with Master: 747c3382653b46cf8173285cb8641d8d (127.29.138.1:35043)
I20260812 06:16:31.450901 30248 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012386581s
I20260812 06:16:31.452369 30281 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:56224
I20260812 06:16:31.461024 30281 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:56238:
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:16:31.481963 30395 tablet_service.cc:1511] Processing CreateTablet for tablet 559f915bc53b47fba642c1ca7023f5e5 (DEFAULT_TABLE table=heavy-update-compaction-test [id=b3d27ff014594cb099eecf6f3f97e25a]), partition=
I20260812 06:16:31.482424 30395 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 559f915bc53b47fba642c1ca7023f5e5. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:31.485329 30450 tablet_bootstrap.cc:492] T 559f915bc53b47fba642c1ca7023f5e5 P 747c3382653b46cf8173285cb8641d8d: Bootstrap starting.
I20260812 06:16:31.486507 30450 tablet_bootstrap.cc:654] T 559f915bc53b47fba642c1ca7023f5e5 P 747c3382653b46cf8173285cb8641d8d: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:31.487671 30450 tablet_bootstrap.cc:492] T 559f915bc53b47fba642c1ca7023f5e5 P 747c3382653b46cf8173285cb8641d8d: No bootstrap required, opened a new log
I20260812 06:16:31.487758 30450 ts_tablet_manager.cc:1403] T 559f915bc53b47fba642c1ca7023f5e5 P 747c3382653b46cf8173285cb8641d8d: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:16:31.488328 30450 raft_consensus.cc:359] T 559f915bc53b47fba642c1ca7023f5e5 P 747c3382653b46cf8173285cb8641d8d [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "747c3382653b46cf8173285cb8641d8d" member_type: VOTER last_known_addr { host: "127.29.138.1" port: 35043 } }
I20260812 06:16:31.488430 30450 raft_consensus.cc:385] T 559f915bc53b47fba642c1ca7023f5e5 P 747c3382653b46cf8173285cb8641d8d [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:31.488453 30450 raft_consensus.cc:740] T 559f915bc53b47fba642c1ca7023f5e5 P 747c3382653b46cf8173285cb8641d8d [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 747c3382653b46cf8173285cb8641d8d, State: Initialized, Role: FOLLOWER
I20260812 06:16:31.488610 30450 consensus_queue.cc:260] T 559f915bc53b47fba642c1ca7023f5e5 P 747c3382653b46cf8173285cb8641d8d [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: "747c3382653b46cf8173285cb8641d8d" member_type: VOTER last_known_addr { host: "127.29.138.1" port: 35043 } }
I20260812 06:16:31.488714 30450 raft_consensus.cc:399] T 559f915bc53b47fba642c1ca7023f5e5 P 747c3382653b46cf8173285cb8641d8d [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:31.488765 30450 raft_consensus.cc:493] T 559f915bc53b47fba642c1ca7023f5e5 P 747c3382653b46cf8173285cb8641d8d [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:31.488822 30450 raft_consensus.cc:3060] T 559f915bc53b47fba642c1ca7023f5e5 P 747c3382653b46cf8173285cb8641d8d [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:31.489702 30450 raft_consensus.cc:515] T 559f915bc53b47fba642c1ca7023f5e5 P 747c3382653b46cf8173285cb8641d8d [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "747c3382653b46cf8173285cb8641d8d" member_type: VOTER last_known_addr { host: "127.29.138.1" port: 35043 } }
I20260812 06:16:31.489864 30450 leader_election.cc:304] T 559f915bc53b47fba642c1ca7023f5e5 P 747c3382653b46cf8173285cb8641d8d [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: 747c3382653b46cf8173285cb8641d8d; no voters: 
I20260812 06:16:31.490091 30450 leader_election.cc:290] T 559f915bc53b47fba642c1ca7023f5e5 P 747c3382653b46cf8173285cb8641d8d [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:31.490275 30452 raft_consensus.cc:2804] T 559f915bc53b47fba642c1ca7023f5e5 P 747c3382653b46cf8173285cb8641d8d [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:31.490453 30450 ts_tablet_manager.cc:1434] T 559f915bc53b47fba642c1ca7023f5e5 P 747c3382653b46cf8173285cb8641d8d: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:16:31.490556 30452 raft_consensus.cc:697] T 559f915bc53b47fba642c1ca7023f5e5 P 747c3382653b46cf8173285cb8641d8d [term 1 LEADER]: Becoming Leader. State: Replica: 747c3382653b46cf8173285cb8641d8d, State: Running, Role: LEADER
I20260812 06:16:31.490691 30434 heartbeater.cc:499] Master 127.29.138.62:43079 was elected leader, sending a full tablet report...
I20260812 06:16:31.490757 30452 consensus_queue.cc:237] T 559f915bc53b47fba642c1ca7023f5e5 P 747c3382653b46cf8173285cb8641d8d [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: "747c3382653b46cf8173285cb8641d8d" member_type: VOTER last_known_addr { host: "127.29.138.1" port: 35043 } }
I20260812 06:16:31.493476 30281 catalog_manager.cc:5719] T 559f915bc53b47fba642c1ca7023f5e5 P 747c3382653b46cf8173285cb8641d8d reported cstate change: term changed from 0 to 1, leader changed from <none> to 747c3382653b46cf8173285cb8641d8d (127.29.138.1). New cstate: current_term: 1 leader_uuid: "747c3382653b46cf8173285cb8641d8d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "747c3382653b46cf8173285cb8641d8d" member_type: VOTER last_known_addr { host: "127.29.138.1" port: 35043 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:31.587591 30248 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.085s	user 0.013s	sys 0.028s
I20260812 06:16:31.689013 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling FlushMRSOp(559f915bc53b47fba642c1ca7023f5e5): perf score=15.086190
I20260812 06:16:31.848126 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: FlushMRSOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.159s	user 0.123s	sys 0.036s Metrics: {"bytes_written":9763995,"cfile_init":1,"compiler_manager_pool.queue_time_us":215,"delete_count":0,"dirs.queue_time_us":80,"dirs.run_cpu_time_us":239,"dirs.run_wall_time_us":1073,"drs_written":1,"lbm_read_time_us":76,"lbm_reads_lt_1ms":4,"lbm_write_time_us":39650,"lbm_writes_lt_1ms":595,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"spinlock_wait_cycles":168192,"thread_start_us":137,"threads_started":1,"update_count":1190}
I20260812 06:16:31.849453 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling LogGCOp(559f915bc53b47fba642c1ca7023f5e5): free 8725963 bytes of WAL
I20260812 06:16:31.849802 30367 log_reader.cc:385] T 559f915bc53b47fba642c1ca7023f5e5: removed 1 log segments from log reader
I20260812 06:16:31.849906 30367 log.cc:1079] T 559f915bc53b47fba642c1ca7023f5e5 P 747c3382653b46cf8173285cb8641d8d: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/559f915bc53b47fba642c1ca7023f5e5/wal-000000001 (ops 1-6)
I20260812 06:16:31.852484 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: LogGCOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.003s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:16:31.852846 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5): perf score=1.196750
I20260812 06:16:31.872125 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.019s	user 0.000s	sys 0.008s Metrics: {"bytes_written":2543704,"delete_count":0,"lbm_write_time_us":3565,"lbm_writes_lt_1ms":65,"reinsert_count":0,"update_count":310}
I20260812 06:16:31.872614 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling UndoDeltaBlockGCOp(559f915bc53b47fba642c1ca7023f5e5): 12308959 bytes on disk
I20260812 06:16:31.873198 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: UndoDeltaBlockGCOp(559f915bc53b47fba642c1ca7023f5e5) 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:16:31.873613 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5): perf score=2.188937
I20260812 06:16:31.889108 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5833,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:31.889998 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling MajorDeltaCompactionOp(559f915bc53b47fba642c1ca7023f5e5): perf score=1.000000
I20260812 06:16:32.058393 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: MajorDeltaCompactionOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.168s	user 0.083s	sys 0.084s Metrics: {"cfile_cache_miss":433,"cfile_cache_miss_bytes":20631393,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":828,"lbm_read_time_us":10291,"lbm_reads_lt_1ms":469,"lbm_write_time_us":45188,"lbm_writes_lt_1ms":443,"mutex_wait_us":26,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12416,"thread_start_us":334,"threads_started":5,"update_count":2000}
I20260812 06:16:32.058996 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5): perf score=11.118625
I20260812 06:16:32.104027 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.045s	user 0.015s	sys 0.023s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17977,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:32.104707 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5): perf score=2.188937
I20260812 06:16:32.116034 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4439,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:32.116523 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5): perf score=2.188937
I20260812 06:16:32.126690 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.010s	user 0.005s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4111,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:32.127139 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling MajorDeltaCompactionOp(559f915bc53b47fba642c1ca7023f5e5): perf score=1.000000
I20260812 06:16:32.286386 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: MajorDeltaCompactionOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.159s	user 0.105s	sys 0.043s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733834,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":210,"lbm_read_time_us":11154,"lbm_reads_lt_1ms":573,"lbm_write_time_us":32509,"lbm_writes_lt_1ms":543,"mutex_wait_us":80,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:16:32.287014 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5): perf score=14.095187
I20260812 06:16:32.337378 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.050s	user 0.018s	sys 0.027s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22315,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:32.337836 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5): perf score=2.188937
I20260812 06:16:32.349602 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.012s	user 0.001s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4572,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:32.350186 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling MajorDeltaCompactionOp(559f915bc53b47fba642c1ca7023f5e5): perf score=1.000000
I20260812 06:16:32.518958 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: MajorDeltaCompactionOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.169s	user 0.125s	sys 0.026s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":634,"lbm_read_time_us":10623,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32302,"lbm_writes_lt_1ms":543,"mutex_wait_us":347,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":2500}
I20260812 06:16:32.519620 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5): perf score=14.095187
I20260812 06:16:32.576658 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.057s	user 0.039s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24097,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:16:32.577126 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5): perf score=2.188937
I20260812 06:16:32.588333 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4325,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:32.588960 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling MajorDeltaCompactionOp(559f915bc53b47fba642c1ca7023f5e5): perf score=1.000000
I20260812 06:16:32.770119 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: MajorDeltaCompactionOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.181s	user 0.129s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":292,"lbm_read_time_us":11641,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31935,"lbm_writes_lt_1ms":543,"mutex_wait_us":68,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10240,"update_count":2500}
I20260812 06:16:32.770782 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5): perf score=14.095187
I20260812 06:16:32.836122 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.065s	user 0.029s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":27343,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:32.836707 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling MajorDeltaCompactionOp(559f915bc53b47fba642c1ca7023f5e5): perf score=1.000000
I20260812 06:16:33.002657 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: MajorDeltaCompactionOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.166s	user 0.113s	sys 0.053s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20631192,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":236,"lbm_read_time_us":12465,"lbm_reads_lt_1ms":463,"lbm_write_time_us":29455,"lbm_writes_lt_1ms":443,"mutex_wait_us":52,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":37120,"update_count":2000}
I20260812 06:16:33.003386 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5): perf score=14.095187
I20260812 06:16:33.057353 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.054s	user 0.033s	sys 0.019s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":24647,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:33.057874 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5): perf score=2.188937
I20260812 06:16:33.069695 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.012s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4660,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:33.070145 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling FlushMRSOp(559f915bc53b47fba642c1ca7023f5e5): perf score=1.000000
I20260812 06:16:33.107584 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: FlushMRSOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.037s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1152509,"cfile_init":1,"dirs.queue_time_us":58,"dirs.run_cpu_time_us":295,"dirs.run_wall_time_us":1330,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1495,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:16:33.108534 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling LogGCOp(559f915bc53b47fba642c1ca7023f5e5): free 124257191 bytes of WAL
I20260812 06:16:33.108783 30367 log_reader.cc:385] T 559f915bc53b47fba642c1ca7023f5e5: removed 12 log segments from log reader
I20260812 06:16:33.108831 30367 log.cc:1079] T 559f915bc53b47fba642c1ca7023f5e5 P 747c3382653b46cf8173285cb8641d8d: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/559f915bc53b47fba642c1ca7023f5e5/wal-000000002 (ops 7-11)
I20260812 06:16:33.108861 30367 log.cc:1079] T 559f915bc53b47fba642c1ca7023f5e5 P 747c3382653b46cf8173285cb8641d8d: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/559f915bc53b47fba642c1ca7023f5e5/wal-000000003 (ops 12-16)
I20260812 06:16:33.108929 30367 log.cc:1079] T 559f915bc53b47fba642c1ca7023f5e5 P 747c3382653b46cf8173285cb8641d8d: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/559f915bc53b47fba642c1ca7023f5e5/wal-000000004 (ops 17-21)
I20260812 06:16:33.108964 30367 log.cc:1079] T 559f915bc53b47fba642c1ca7023f5e5 P 747c3382653b46cf8173285cb8641d8d: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/559f915bc53b47fba642c1ca7023f5e5/wal-000000005 (ops 22-26)
I20260812 06:16:33.109006 30367 log.cc:1079] T 559f915bc53b47fba642c1ca7023f5e5 P 747c3382653b46cf8173285cb8641d8d: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/559f915bc53b47fba642c1ca7023f5e5/wal-000000006 (ops 27-31)
I20260812 06:16:33.109073 30367 log.cc:1079] T 559f915bc53b47fba642c1ca7023f5e5 P 747c3382653b46cf8173285cb8641d8d: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/559f915bc53b47fba642c1ca7023f5e5/wal-000000007 (ops 32-36)
I20260812 06:16:33.109118 30367 log.cc:1079] T 559f915bc53b47fba642c1ca7023f5e5 P 747c3382653b46cf8173285cb8641d8d: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/559f915bc53b47fba642c1ca7023f5e5/wal-000000008 (ops 37-41)
I20260812 06:16:33.109158 30367 log.cc:1079] T 559f915bc53b47fba642c1ca7023f5e5 P 747c3382653b46cf8173285cb8641d8d: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/559f915bc53b47fba642c1ca7023f5e5/wal-000000009 (ops 42-46)
I20260812 06:16:33.109200 30367 log.cc:1079] T 559f915bc53b47fba642c1ca7023f5e5 P 747c3382653b46cf8173285cb8641d8d: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/559f915bc53b47fba642c1ca7023f5e5/wal-000000010 (ops 47-50)
I20260812 06:16:33.109239 30367 log.cc:1079] T 559f915bc53b47fba642c1ca7023f5e5 P 747c3382653b46cf8173285cb8641d8d: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/559f915bc53b47fba642c1ca7023f5e5/wal-000000011 (ops 51-55)
I20260812 06:16:33.109277 30367 log.cc:1079] T 559f915bc53b47fba642c1ca7023f5e5 P 747c3382653b46cf8173285cb8641d8d: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/559f915bc53b47fba642c1ca7023f5e5/wal-000000012 (ops 56-60)
I20260812 06:16:33.109316 30367 log.cc:1079] T 559f915bc53b47fba642c1ca7023f5e5 P 747c3382653b46cf8173285cb8641d8d: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/559f915bc53b47fba642c1ca7023f5e5/wal-000000013 (ops 61-65)
I20260812 06:16:33.138811 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: LogGCOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.030s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:16:33.139189 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5): perf score=4.173312
I20260812 06:16:33.152868 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.013s	user 0.001s	sys 0.011s Metrics: {"bytes_written":5415441,"delete_count":0,"lbm_write_time_us":5469,"lbm_writes_lt_1ms":135,"reinsert_count":0,"update_count":660}
I20260812 06:16:33.153294 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5): perf score=1.196750
I20260812 06:16:33.161198 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.008s	user 0.002s	sys 0.005s Metrics: {"bytes_written":2789855,"delete_count":0,"lbm_write_time_us":2859,"lbm_writes_lt_1ms":71,"reinsert_count":0,"update_count":340}
I20260812 06:16:33.161695 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling MajorDeltaCompactionOp(559f915bc53b47fba642c1ca7023f5e5): perf score=1.000000
I20260812 06:16:33.404654 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: MajorDeltaCompactionOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.243s	user 0.155s	sys 0.084s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32938759,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":668,"dirs.run_cpu_time_us":416,"dirs.run_wall_time_us":2415,"lbm_read_time_us":17104,"lbm_reads_lt_1ms":774,"lbm_write_time_us":42501,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":3500}
I20260812 06:16:33.405367 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling UndoDeltaBlockGCOp(559f915bc53b47fba642c1ca7023f5e5): 448 bytes on disk
I20260812 06:16:33.406651 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: UndoDeltaBlockGCOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":86,"lbm_reads_lt_1ms":4}
I20260812 06:16:33.408423 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5): perf score=16.079562
I20260812 06:16:33.482733 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.074s	user 0.032s	sys 0.025s Metrics: {"bytes_written":17640629,"delete_count":0,"lbm_write_time_us":27768,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":432,"reinsert_count":0,"update_count":2150}
I20260812 06:16:33.483283 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5): perf score=5.165500
I20260812 06:16:33.503118 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.020s	user 0.006s	sys 0.011s Metrics: {"bytes_written":6974360,"delete_count":0,"lbm_write_time_us":8236,"lbm_writes_lt_1ms":173,"reinsert_count":0,"update_count":850}
I20260812 06:16:33.503640 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling MajorDeltaCompactionOp(559f915bc53b47fba642c1ca7023f5e5): perf score=1.000000
I20260812 06:16:33.718777 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: MajorDeltaCompactionOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.215s	user 0.118s	sys 0.091s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28836146,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":362,"lbm_read_time_us":14927,"lbm_reads_lt_1ms":664,"lbm_write_time_us":34871,"lbm_writes_lt_1ms":643,"mutex_wait_us":47,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":20224,"update_count":3000}
I20260812 06:16:33.719512 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5): perf score=17.071750
I20260812 06:16:33.780653 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.061s	user 0.051s	sys 0.008s Metrics: {"bytes_written":18625207,"delete_count":0,"lbm_write_time_us":27187,"lbm_writes_lt_1ms":457,"reinsert_count":0,"update_count":2270}
I20260812 06:16:33.781314 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5): perf score=1.196750
I20260812 06:16:33.791564 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.010s	user 0.005s	sys 0.001s Metrics: {"bytes_written":2297558,"delete_count":0,"lbm_write_time_us":2380,"lbm_writes_lt_1ms":59,"reinsert_count":0,"update_count":280}
I20260812 06:16:33.792062 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5): perf score=2.188937
I20260812 06:16:33.801972 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3591,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:33.802466 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling MajorDeltaCompactionOp(559f915bc53b47fba642c1ca7023f5e5): perf score=1.000000
I20260812 06:16:34.015586 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: MajorDeltaCompactionOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.213s	user 0.120s	sys 0.092s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28836205,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":345,"lbm_read_time_us":15355,"lbm_reads_lt_1ms":673,"lbm_write_time_us":37481,"lbm_writes_lt_1ms":643,"mutex_wait_us":77,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":3000}
I20260812 06:16:34.016394 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5): perf score=14.095187
I20260812 06:16:34.077834 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.061s	user 0.032s	sys 0.017s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":22505,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:34.078310 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5): perf score=2.188937
I20260812 06:16:34.090610 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.012s	user 0.001s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4411,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:34.091202 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling MajorDeltaCompactionOp(559f915bc53b47fba642c1ca7023f5e5): perf score=1.000000
I20260812 06:16:34.272234 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: MajorDeltaCompactionOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.181s	user 0.138s	sys 0.039s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733726,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":706,"lbm_read_time_us":11771,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31870,"lbm_writes_lt_1ms":543,"mutex_wait_us":62,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13696,"update_count":2500}
I20260812 06:16:34.273114 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5): perf score=14.095187
I20260812 06:16:34.337527 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.064s	user 0.042s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21967,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:34.338114 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5): perf score=2.188937
I20260812 06:16:34.349466 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4530,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:34.349943 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling MajorDeltaCompactionOp(559f915bc53b47fba642c1ca7023f5e5): perf score=1.000000
I20260812 06:16:34.538784 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: MajorDeltaCompactionOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.189s	user 0.125s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733722,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":292,"lbm_read_time_us":13301,"lbm_reads_lt_1ms":572,"lbm_write_time_us":35981,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":542,"mutex_wait_us":59,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":104576,"update_count":2500}
I20260812 06:16:34.539599 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5): perf score=14.095187
I20260812 06:16:34.608552 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.069s	user 0.020s	sys 0.048s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":28152,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:34.609148 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5): perf score=2.188937
I20260812 06:16:34.627094 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.018s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7057,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:34.627712 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling FlushMRSOp(559f915bc53b47fba642c1ca7023f5e5): perf score=1.000000
I20260812 06:16:34.678632 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: FlushMRSOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.051s	user 0.038s	sys 0.001s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":77,"dirs.run_cpu_time_us":263,"dirs.run_wall_time_us":1585,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1548,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:16:34.679520 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling LogGCOp(559f915bc53b47fba642c1ca7023f5e5): free 112692447 bytes of WAL
I20260812 06:16:34.679806 30367 log_reader.cc:385] T 559f915bc53b47fba642c1ca7023f5e5: removed 11 log segments from log reader
I20260812 06:16:34.679881 30367 log.cc:1079] T 559f915bc53b47fba642c1ca7023f5e5 P 747c3382653b46cf8173285cb8641d8d: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/559f915bc53b47fba642c1ca7023f5e5/wal-000000014 (ops 66-70)
I20260812 06:16:34.679958 30367 log.cc:1079] T 559f915bc53b47fba642c1ca7023f5e5 P 747c3382653b46cf8173285cb8641d8d: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/559f915bc53b47fba642c1ca7023f5e5/wal-000000015 (ops 71-75)
I20260812 06:16:34.680011 30367 log.cc:1079] T 559f915bc53b47fba642c1ca7023f5e5 P 747c3382653b46cf8173285cb8641d8d: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/559f915bc53b47fba642c1ca7023f5e5/wal-000000016 (ops 76-80)
I20260812 06:16:34.680054 30367 log.cc:1079] T 559f915bc53b47fba642c1ca7023f5e5 P 747c3382653b46cf8173285cb8641d8d: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/559f915bc53b47fba642c1ca7023f5e5/wal-000000017 (ops 81-85)
I20260812 06:16:34.680135 30367 log.cc:1079] T 559f915bc53b47fba642c1ca7023f5e5 P 747c3382653b46cf8173285cb8641d8d: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/559f915bc53b47fba642c1ca7023f5e5/wal-000000018 (ops 86-90)
I20260812 06:16:34.680178 30367 log.cc:1079] T 559f915bc53b47fba642c1ca7023f5e5 P 747c3382653b46cf8173285cb8641d8d: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/559f915bc53b47fba642c1ca7023f5e5/wal-000000019 (ops 91-95)
I20260812 06:16:34.680215 30367 log.cc:1079] T 559f915bc53b47fba642c1ca7023f5e5 P 747c3382653b46cf8173285cb8641d8d: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/559f915bc53b47fba642c1ca7023f5e5/wal-000000020 (ops 96-100)
I20260812 06:16:34.680253 30367 log.cc:1079] T 559f915bc53b47fba642c1ca7023f5e5 P 747c3382653b46cf8173285cb8641d8d: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/559f915bc53b47fba642c1ca7023f5e5/wal-000000021 (ops 101-105)
I20260812 06:16:34.680289 30367 log.cc:1079] T 559f915bc53b47fba642c1ca7023f5e5 P 747c3382653b46cf8173285cb8641d8d: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/559f915bc53b47fba642c1ca7023f5e5/wal-000000022 (ops 106-110)
I20260812 06:16:34.680325 30367 log.cc:1079] T 559f915bc53b47fba642c1ca7023f5e5 P 747c3382653b46cf8173285cb8641d8d: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/559f915bc53b47fba642c1ca7023f5e5/wal-000000023 (ops 111-115)
I20260812 06:16:34.680362 30367 log.cc:1079] T 559f915bc53b47fba642c1ca7023f5e5 P 747c3382653b46cf8173285cb8641d8d: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/559f915bc53b47fba642c1ca7023f5e5/wal-000000024 (ops 116-120)
I20260812 06:16:34.708264 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: LogGCOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.029s	user 0.001s	sys 0.027s Metrics: {}
I20260812 06:16:34.708922 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling UndoDeltaBlockGCOp(559f915bc53b47fba642c1ca7023f5e5): 462 bytes on disk
I20260812 06:16:34.709532 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: UndoDeltaBlockGCOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:16:34.710189 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5): perf score=3.181125
I20260812 06:16:34.723779 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.013s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4530,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:34.724373 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5): perf score=2.188937
I20260812 06:16:34.734201 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3583,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:34.734910 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling MajorDeltaCompactionOp(559f915bc53b47fba642c1ca7023f5e5): perf score=1.000000
I20260812 06:16:34.972626 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: MajorDeltaCompactionOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.237s	user 0.132s	sys 0.104s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32938776,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":881,"lbm_read_time_us":17515,"lbm_reads_lt_1ms":774,"lbm_write_time_us":43169,"lbm_writes_lt_1ms":743,"mutex_wait_us":372,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":13312,"thread_start_us":87,"threads_started":1,"update_count":3500}
I20260812 06:16:34.973493 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5): perf score=14.095187
I20260812 06:16:35.032666 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.059s	user 0.029s	sys 0.017s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":20128,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:35.033182 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5): perf score=3.181125
I20260812 06:16:35.055231 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.022s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4745,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:35.055768 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5): perf score=2.188937
I20260812 06:16:35.066018 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3917,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:35.066473 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling MajorDeltaCompactionOp(559f915bc53b47fba642c1ca7023f5e5): perf score=1.000000
I20260812 06:16:35.276450 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: MajorDeltaCompactionOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.210s	user 0.166s	sys 0.043s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28836247,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":895,"lbm_read_time_us":16796,"lbm_reads_lt_1ms":673,"lbm_write_time_us":33593,"lbm_writes_lt_1ms":643,"mutex_wait_us":425,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":11136,"update_count":3000}
I20260812 06:16:35.277311 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5): perf score=14.095187
I20260812 06:16:35.341284 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.064s	user 0.042s	sys 0.008s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":22692,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:35.341810 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5): perf score=2.188937
I20260812 06:16:35.354305 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4254,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:35.354753 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling MajorDeltaCompactionOp(559f915bc53b47fba642c1ca7023f5e5): perf score=1.000000
I20260812 06:16:35.541277 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: MajorDeltaCompactionOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.186s	user 0.139s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733722,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":268,"lbm_read_time_us":12489,"lbm_reads_lt_1ms":572,"lbm_write_time_us":37660,"lbm_writes_lt_1ms":543,"mutex_wait_us":47,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6528,"update_count":2500}
I20260812 06:16:35.541985 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5): perf score=14.095187
I20260812 06:16:35.608503 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.066s	user 0.029s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":26235,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:35.609105 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5): perf score=2.188937
I20260812 06:16:35.620231 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4303,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:35.620721 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling MajorDeltaCompactionOp(559f915bc53b47fba642c1ca7023f5e5): perf score=1.000000
I20260812 06:16:35.805891 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: MajorDeltaCompactionOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.185s	user 0.116s	sys 0.068s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733722,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":221,"lbm_read_time_us":12528,"lbm_reads_lt_1ms":572,"lbm_write_time_us":37984,"lbm_writes_lt_1ms":543,"mutex_wait_us":73,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16256,"update_count":2500}
I20260812 06:16:35.806619 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5): perf score=14.095187
I20260812 06:16:35.869284 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.062s	user 0.023s	sys 0.035s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":22824,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:35.869889 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5): perf score=2.188937
I20260812 06:16:35.887123 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.017s	user 0.007s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6374,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:35.887764 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling MajorDeltaCompactionOp(559f915bc53b47fba642c1ca7023f5e5): perf score=1.000000
I20260812 06:16:36.076802 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: MajorDeltaCompactionOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.189s	user 0.126s	sys 0.063s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733719,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":222,"lbm_read_time_us":14995,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34093,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11136,"update_count":2500}
I20260812 06:16:36.077587 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5): perf score=10.126437
I20260812 06:16:36.119028 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.041s	user 0.018s	sys 0.020s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":18997,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:36.120061 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5): perf score=2.188937
I20260812 06:16:36.138640 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.018s	user 0.009s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6328,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:36.139144 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling FlushMRSOp(559f915bc53b47fba642c1ca7023f5e5): perf score=1.000000
I20260812 06:16:36.187441 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: FlushMRSOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.048s	user 0.029s	sys 0.001s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":83,"dirs.run_cpu_time_us":230,"dirs.run_wall_time_us":1534,"drs_written":1,"lbm_read_time_us":95,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2459,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:16:36.188350 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling LogGCOp(559f915bc53b47fba642c1ca7023f5e5): free 115490325 bytes of WAL
I20260812 06:16:36.188665 30367 log_reader.cc:385] T 559f915bc53b47fba642c1ca7023f5e5: removed 11 log segments from log reader
I20260812 06:16:36.188730 30367 log.cc:1079] T 559f915bc53b47fba642c1ca7023f5e5 P 747c3382653b46cf8173285cb8641d8d: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/559f915bc53b47fba642c1ca7023f5e5/wal-000000025 (ops 121-125)
I20260812 06:16:36.188769 30367 log.cc:1079] T 559f915bc53b47fba642c1ca7023f5e5 P 747c3382653b46cf8173285cb8641d8d: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/559f915bc53b47fba642c1ca7023f5e5/wal-000000026 (ops 126-130)
I20260812 06:16:36.188800 30367 log.cc:1079] T 559f915bc53b47fba642c1ca7023f5e5 P 747c3382653b46cf8173285cb8641d8d: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/559f915bc53b47fba642c1ca7023f5e5/wal-000000027 (ops 131-135)
I20260812 06:16:36.188824 30367 log.cc:1079] T 559f915bc53b47fba642c1ca7023f5e5 P 747c3382653b46cf8173285cb8641d8d: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/559f915bc53b47fba642c1ca7023f5e5/wal-000000028 (ops 136-140)
I20260812 06:16:36.188854 30367 log.cc:1079] T 559f915bc53b47fba642c1ca7023f5e5 P 747c3382653b46cf8173285cb8641d8d: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/559f915bc53b47fba642c1ca7023f5e5/wal-000000029 (ops 141-145)
I20260812 06:16:36.188882 30367 log.cc:1079] T 559f915bc53b47fba642c1ca7023f5e5 P 747c3382653b46cf8173285cb8641d8d: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/559f915bc53b47fba642c1ca7023f5e5/wal-000000030 (ops 146-150)
I20260812 06:16:36.188908 30367 log.cc:1079] T 559f915bc53b47fba642c1ca7023f5e5 P 747c3382653b46cf8173285cb8641d8d: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/559f915bc53b47fba642c1ca7023f5e5/wal-000000031 (ops 151-155)
I20260812 06:16:36.188934 30367 log.cc:1079] T 559f915bc53b47fba642c1ca7023f5e5 P 747c3382653b46cf8173285cb8641d8d: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/559f915bc53b47fba642c1ca7023f5e5/wal-000000032 (ops 156-160)
I20260812 06:16:36.188961 30367 log.cc:1079] T 559f915bc53b47fba642c1ca7023f5e5 P 747c3382653b46cf8173285cb8641d8d: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/559f915bc53b47fba642c1ca7023f5e5/wal-000000033 (ops 161-165)
I20260812 06:16:36.188988 30367 log.cc:1079] T 559f915bc53b47fba642c1ca7023f5e5 P 747c3382653b46cf8173285cb8641d8d: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/559f915bc53b47fba642c1ca7023f5e5/wal-000000034 (ops 166-170)
I20260812 06:16:36.189018 30367 log.cc:1079] T 559f915bc53b47fba642c1ca7023f5e5 P 747c3382653b46cf8173285cb8641d8d: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/559f915bc53b47fba642c1ca7023f5e5/wal-000000035 (ops 171-174)
I20260812 06:16:36.218513 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: LogGCOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.030s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:16:36.219177 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling UndoDeltaBlockGCOp(559f915bc53b47fba642c1ca7023f5e5): 447 bytes on disk
I20260812 06:16:36.219813 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: UndoDeltaBlockGCOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":85,"lbm_reads_lt_1ms":4}
I20260812 06:16:36.220846 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5): perf score=5.165500
I20260812 06:16:36.244925 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.024s	user 0.019s	sys 0.004s Metrics: {"bytes_written":7261523,"delete_count":0,"lbm_write_time_us":9871,"lbm_writes_lt_1ms":180,"reinsert_count":0,"update_count":885}
I20260812 06:16:36.245607 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling LogGCOp(559f915bc53b47fba642c1ca7023f5e5): free 8767140 bytes of WAL
I20260812 06:16:36.245879 30367 log_reader.cc:385] T 559f915bc53b47fba642c1ca7023f5e5: removed 1 log segments from log reader
I20260812 06:16:36.245957 30367 log.cc:1079] T 559f915bc53b47fba642c1ca7023f5e5 P 747c3382653b46cf8173285cb8641d8d: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/559f915bc53b47fba642c1ca7023f5e5/wal-000000036 (ops 175-179)
I20260812 06:16:36.248651 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: LogGCOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.003s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:16:36.249187 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling MajorDeltaCompactionOp(559f915bc53b47fba642c1ca7023f5e5): perf score=1.000000
I20260812 06:16:36.452442 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: MajorDeltaCompactionOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.203s	user 0.119s	sys 0.081s Metrics: {"cfile_cache_miss":610,"cfile_cache_miss_bytes":27892703,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":2912,"lbm_read_time_us":15847,"lbm_reads_lt_1ms":646,"lbm_write_time_us":35519,"lbm_writes_lt_1ms":620,"mutex_wait_us":2698,"peak_mem_usage":72517899,"reinsert_count":0,"spinlock_wait_cycles":7936,"thread_start_us":98,"threads_started":1,"update_count":2885}
I20260812 06:16:36.453366 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5): perf score=15.087375
I20260812 06:16:36.519634 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.066s	user 0.032s	sys 0.030s Metrics: {"bytes_written":17353459,"delete_count":0,"lbm_write_time_us":23619,"lbm_writes_lt_1ms":426,"reinsert_count":0,"update_count":2115}
I20260812 06:16:36.520465 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5): perf score=2.188937
I20260812 06:16:36.531755 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4414,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:36.532279 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling MajorDeltaCompactionOp(559f915bc53b47fba642c1ca7023f5e5): perf score=1.000000
I20260812 06:16:36.718962 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: MajorDeltaCompactionOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.186s	user 0.116s	sys 0.062s Metrics: {"cfile_cache_miss":555,"cfile_cache_miss_bytes":25677281,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":286,"lbm_read_time_us":14061,"lbm_reads_lt_1ms":595,"lbm_write_time_us":31636,"lbm_writes_lt_1ms":566,"mutex_wait_us":50,"peak_mem_usage":65100089,"reinsert_count":0,"spinlock_wait_cycles":9472,"update_count":2615}
I20260812 06:16:36.719601 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5): perf score=14.095187
I20260812 06:16:36.785565 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.066s	user 0.020s	sys 0.036s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21820,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:36.786187 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5): perf score=2.188937
I20260812 06:16:36.796904 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: FlushDeltaMemStoresOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4201,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:36.797395 30435 maintenance_manager.cc:419] P 747c3382653b46cf8173285cb8641d8d: Scheduling MajorDeltaCompactionOp(559f915bc53b47fba642c1ca7023f5e5): perf score=1.000000
I20260812 06:16:36.845495 30248 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.258s	user 1.858s	sys 0.193s
I20260812 06:16:36.918934 30248 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.073s	user 0.001s	sys 0.000s
I20260812 06:16:36.919596 30248 tablet_server.cc:179] TabletServer@127.29.138.1:0 shutting down...
I20260812 06:16:36.957580 30367 maintenance_manager.cc:643] P 747c3382653b46cf8173285cb8641d8d: MajorDeltaCompactionOp(559f915bc53b47fba642c1ca7023f5e5) complete. Timing: real 0.160s	user 0.098s	sys 0.061s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":401,"lbm_read_time_us":12376,"lbm_reads_lt_1ms":568,"lbm_write_time_us":28545,"lbm_writes_lt_1ms":543,"mutex_wait_us":88,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:16:36.958771 30248 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:16:36.959156 30248 tablet_replica.cc:333] T 559f915bc53b47fba642c1ca7023f5e5 P 747c3382653b46cf8173285cb8641d8d: stopping tablet replica
I20260812 06:16:36.959406 30248 raft_consensus.cc:2243] T 559f915bc53b47fba642c1ca7023f5e5 P 747c3382653b46cf8173285cb8641d8d [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:36.959649 30248 raft_consensus.cc:2272] T 559f915bc53b47fba642c1ca7023f5e5 P 747c3382653b46cf8173285cb8641d8d [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:36.976649 30248 tablet_server.cc:196] TabletServer@127.29.138.1:0 shutdown complete.
I20260812 06:16:37.004597 30248 master.cc:562] Master@127.29.138.62:43079 shutting down...
I20260812 06:16:37.008257 30248 raft_consensus.cc:2243] T 00000000000000000000000000000000 P f252b3b855c4473db499b668c5c8053f [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:37.008435 30248 raft_consensus.cc:2272] T 00000000000000000000000000000000 P f252b3b855c4473db499b668c5c8053f [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:37.008490 30248 tablet_replica.cc:333] T 00000000000000000000000000000000 P f252b3b855c4473db499b668c5c8053f: stopping tablet replica
I20260812 06:16:37.020962 30248 master.cc:584] Master@127.29.138.62:43079 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5849 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:16:37.134955 30248 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.29.138.62:33663
I20260812 06:16:37.135471 30248 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:37.138129 30471 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:16:37.138141 30474 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:16:37.138089 30472 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:16:37.138089 30248 server_base.cc:1061] running on GCE node
I20260812 06:16:37.138609 30248 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:37.138670 30248 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:16:37.138697 30248 hybrid_clock.cc:648] HybridClock initialized: now 1786515397138696 us; error 0 us; skew 500 ppm
I20260812 06:16:37.139612 30248 webserver.cc:533] Webserver started at http://127.29.138.62:34707/ using document root <none> and password file <none>
I20260812 06:16:37.139810 30248 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:37.139886 30248 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:37.140000 30248 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:37.140447 30248 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515391260141-30248-0/minicluster-data/master-0-root/instance:
uuid: "93e610442f4046129d48c296a825c2d4"
format_stamp: "Formatted at 2026-08-12 06:16:37 on dist-test-slave-1jjb"
I20260812 06:16:37.142216 30248 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:16:37.143256 30482 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:16:37.143573 30248 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:37.143675 30248 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515391260141-30248-0/minicluster-data/master-0-root
uuid: "93e610442f4046129d48c296a825c2d4"
format_stamp: "Formatted at 2026-08-12 06:16:37 on dist-test-slave-1jjb"
I20260812 06:16:37.143767 30248 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515391260141-30248-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515391260141-30248-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515391260141-30248-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:16:37.155869 30248 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:37.156404 30248 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:37.161020 30248 rpc_server.cc:307] RPC server started. Bound to: 127.29.138.62:33663
I20260812 06:16:37.162489 30541 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.29.138.62:33663 every 8 connection(s)
I20260812 06:16:37.162992 30542 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:16:37.164995 30542 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 93e610442f4046129d48c296a825c2d4: Bootstrap starting.
I20260812 06:16:37.166052 30542 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 93e610442f4046129d48c296a825c2d4: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:37.167225 30542 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 93e610442f4046129d48c296a825c2d4: No bootstrap required, opened a new log
I20260812 06:16:37.167706 30542 raft_consensus.cc:359] T 00000000000000000000000000000000 P 93e610442f4046129d48c296a825c2d4 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "93e610442f4046129d48c296a825c2d4" member_type: VOTER }
I20260812 06:16:37.167804 30542 raft_consensus.cc:385] T 00000000000000000000000000000000 P 93e610442f4046129d48c296a825c2d4 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:37.167826 30542 raft_consensus.cc:740] T 00000000000000000000000000000000 P 93e610442f4046129d48c296a825c2d4 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 93e610442f4046129d48c296a825c2d4, State: Initialized, Role: FOLLOWER
I20260812 06:16:37.168044 30542 consensus_queue.cc:260] T 00000000000000000000000000000000 P 93e610442f4046129d48c296a825c2d4 [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: "93e610442f4046129d48c296a825c2d4" member_type: VOTER }
I20260812 06:16:37.168141 30542 raft_consensus.cc:399] T 00000000000000000000000000000000 P 93e610442f4046129d48c296a825c2d4 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:37.168215 30542 raft_consensus.cc:493] T 00000000000000000000000000000000 P 93e610442f4046129d48c296a825c2d4 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:37.168277 30542 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 93e610442f4046129d48c296a825c2d4 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:37.169070 30542 raft_consensus.cc:515] T 00000000000000000000000000000000 P 93e610442f4046129d48c296a825c2d4 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "93e610442f4046129d48c296a825c2d4" member_type: VOTER }
I20260812 06:16:37.169231 30542 leader_election.cc:304] T 00000000000000000000000000000000 P 93e610442f4046129d48c296a825c2d4 [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: 93e610442f4046129d48c296a825c2d4; no voters: 
I20260812 06:16:37.169477 30542 leader_election.cc:290] T 00000000000000000000000000000000 P 93e610442f4046129d48c296a825c2d4 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:37.169665 30545 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 93e610442f4046129d48c296a825c2d4 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:37.169873 30545 raft_consensus.cc:697] T 00000000000000000000000000000000 P 93e610442f4046129d48c296a825c2d4 [term 1 LEADER]: Becoming Leader. State: Replica: 93e610442f4046129d48c296a825c2d4, State: Running, Role: LEADER
I20260812 06:16:37.170065 30542 sys_catalog.cc:565] T 00000000000000000000000000000000 P 93e610442f4046129d48c296a825c2d4 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:37.170037 30545 consensus_queue.cc:237] T 00000000000000000000000000000000 P 93e610442f4046129d48c296a825c2d4 [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: "93e610442f4046129d48c296a825c2d4" member_type: VOTER }
I20260812 06:16:37.170600 30546 sys_catalog.cc:455] T 00000000000000000000000000000000 P 93e610442f4046129d48c296a825c2d4 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "93e610442f4046129d48c296a825c2d4" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "93e610442f4046129d48c296a825c2d4" member_type: VOTER } }
I20260812 06:16:37.170696 30546 sys_catalog.cc:458] T 00000000000000000000000000000000 P 93e610442f4046129d48c296a825c2d4 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:37.170653 30547 sys_catalog.cc:455] T 00000000000000000000000000000000 P 93e610442f4046129d48c296a825c2d4 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 93e610442f4046129d48c296a825c2d4. Latest consensus state: current_term: 1 leader_uuid: "93e610442f4046129d48c296a825c2d4" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "93e610442f4046129d48c296a825c2d4" member_type: VOTER } }
I20260812 06:16:37.170746 30547 sys_catalog.cc:458] T 00000000000000000000000000000000 P 93e610442f4046129d48c296a825c2d4 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:37.171007 30550 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:37.172025 30550 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:37.172263 30248 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:16:37.174013 30550 catalog_manager.cc:1383] Generated new cluster ID: 5e8f2fceadda4ffebdcd5d440483e5aa
I20260812 06:16:37.174073 30550 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:37.184684 30550 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:37.185320 30550 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:37.197014 30550 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 93e610442f4046129d48c296a825c2d4: Generated new TSK 0
I20260812 06:16:37.197261 30550 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:37.204967 30248 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:37.207114 30566 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:16:37.207158 30570 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:16:37.207170 30248 server_base.cc:1061] running on GCE node
W20260812 06:16:37.207114 30567 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:16:37.207559 30248 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:37.207605 30248 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:16:37.207623 30248 hybrid_clock.cc:648] HybridClock initialized: now 1786515397207622 us; error 0 us; skew 500 ppm
I20260812 06:16:37.208573 30248 webserver.cc:533] Webserver started at http://127.29.138.1:37285/ using document root <none> and password file <none>
I20260812 06:16:37.208715 30248 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:37.208762 30248 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:37.208815 30248 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:37.209264 30248 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515391260141-30248-0/minicluster-data/ts-0-root/instance:
uuid: "19ed44496a304642818732e0e08e5456"
format_stamp: "Formatted at 2026-08-12 06:16:37 on dist-test-slave-1jjb"
I20260812 06:16:37.210793 30248 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:16:37.211799 30575 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:16:37.212052 30248 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:37.212198 30248 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515391260141-30248-0/minicluster-data/ts-0-root
uuid: "19ed44496a304642818732e0e08e5456"
format_stamp: "Formatted at 2026-08-12 06:16:37 on dist-test-slave-1jjb"
I20260812 06:16:37.212291 30248 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515391260141-30248-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515391260141-30248-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515391260141-30248-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:16:37.220620 30248 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:37.221019 30248 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:37.221370 30248 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:37.221899 30248 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:37.221963 30248 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:37.222055 30248 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:37.222105 30248 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:37.227171 30248 rpc_server.cc:307] RPC server started. Bound to: 127.29.138.1:38557
I20260812 06:16:37.229107 30657 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.29.138.1:38557 every 8 connection(s)
I20260812 06:16:37.236909 30658 heartbeater.cc:344] Connected to a master server at 127.29.138.62:33663
I20260812 06:16:37.237064 30658 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:37.237326 30658 heartbeater.cc:507] Master 127.29.138.62:33663 requested a full tablet report, sending...
I20260812 06:16:37.237978 30501 ts_manager.cc:194] Registered new tserver with Master: 19ed44496a304642818732e0e08e5456 (127.29.138.1:38557)
I20260812 06:16:37.238191 30248 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.009959693s
I20260812 06:16:37.238848 30501 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:39942
I20260812 06:16:37.245324 30501 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:39958:
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:16:37.254395 30612 tablet_service.cc:1511] Processing CreateTablet for tablet d63e6433be2c40a9b7aada0c614b5894 (DEFAULT_TABLE table=heavy-update-compaction-test [id=b3deed28596f4ac5a9844e2bc7da93bf]), partition=
I20260812 06:16:37.254715 30612 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet d63e6433be2c40a9b7aada0c614b5894. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:37.256908 30674 tablet_bootstrap.cc:492] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456: Bootstrap starting.
I20260812 06:16:37.257663 30674 tablet_bootstrap.cc:654] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:37.258608 30674 tablet_bootstrap.cc:492] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456: No bootstrap required, opened a new log
I20260812 06:16:37.258683 30674 ts_tablet_manager.cc:1403] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:16:37.259056 30674 raft_consensus.cc:359] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "19ed44496a304642818732e0e08e5456" member_type: VOTER last_known_addr { host: "127.29.138.1" port: 38557 } }
I20260812 06:16:37.259142 30674 raft_consensus.cc:385] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:37.259164 30674 raft_consensus.cc:740] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 19ed44496a304642818732e0e08e5456, State: Initialized, Role: FOLLOWER
I20260812 06:16:37.259364 30674 consensus_queue.cc:260] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456 [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: "19ed44496a304642818732e0e08e5456" member_type: VOTER last_known_addr { host: "127.29.138.1" port: 38557 } }
I20260812 06:16:37.259466 30674 raft_consensus.cc:399] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:37.259493 30674 raft_consensus.cc:493] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:37.259523 30674 raft_consensus.cc:3060] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:37.260368 30674 raft_consensus.cc:515] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "19ed44496a304642818732e0e08e5456" member_type: VOTER last_known_addr { host: "127.29.138.1" port: 38557 } }
I20260812 06:16:37.260524 30674 leader_election.cc:304] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456 [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: 19ed44496a304642818732e0e08e5456; no voters: 
I20260812 06:16:37.260742 30674 leader_election.cc:290] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:37.260890 30676 raft_consensus.cc:2804] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:37.261096 30674 ts_tablet_manager.cc:1434] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456: Time spent starting tablet: real 0.002s	user 0.001s	sys 0.002s
I20260812 06:16:37.261121 30676 raft_consensus.cc:697] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456 [term 1 LEADER]: Becoming Leader. State: Replica: 19ed44496a304642818732e0e08e5456, State: Running, Role: LEADER
I20260812 06:16:37.261126 30658 heartbeater.cc:499] Master 127.29.138.62:33663 was elected leader, sending a full tablet report...
I20260812 06:16:37.261319 30676 consensus_queue.cc:237] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456 [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: "19ed44496a304642818732e0e08e5456" member_type: VOTER last_known_addr { host: "127.29.138.1" port: 38557 } }
I20260812 06:16:37.262616 30501 catalog_manager.cc:5719] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456 reported cstate change: term changed from 0 to 1, leader changed from <none> to 19ed44496a304642818732e0e08e5456 (127.29.138.1). New cstate: current_term: 1 leader_uuid: "19ed44496a304642818732e0e08e5456" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "19ed44496a304642818732e0e08e5456" member_type: VOTER last_known_addr { host: "127.29.138.1" port: 38557 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:37.325474 30248 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.056s	user 0.015s	sys 0.008s
I20260812 06:16:37.479543 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling FlushMRSOp(d63e6433be2c40a9b7aada0c614b5894): perf score=19.054940
I20260812 06:16:37.645872 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: FlushMRSOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.166s	user 0.133s	sys 0.031s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":79,"dirs.run_cpu_time_us":247,"dirs.run_wall_time_us":904,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":45118,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:16:37.646502 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling LogGCOp(d63e6433be2c40a9b7aada0c614b5894): free 20290830 bytes of WAL
I20260812 06:16:37.646775 30581 log_reader.cc:385] T d63e6433be2c40a9b7aada0c614b5894: removed 2 log segments from log reader
I20260812 06:16:37.646822 30581 log.cc:1079] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/d63e6433be2c40a9b7aada0c614b5894/wal-000000001 (ops 1-6)
I20260812 06:16:37.646874 30581 log.cc:1079] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/d63e6433be2c40a9b7aada0c614b5894/wal-000000002 (ops 7-10)
I20260812 06:16:37.651393 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: LogGCOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.005s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:16:37.652107 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894): perf score=2.188937
I20260812 06:16:37.683465 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.031s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6697,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":500}
I20260812 06:16:37.683904 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling UndoDeltaBlockGCOp(d63e6433be2c40a9b7aada0c614b5894): 16411392 bytes on disk
I20260812 06:16:37.684336 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: UndoDeltaBlockGCOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4}
I20260812 06:16:37.684749 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894): perf score=2.188937
I20260812 06:16:37.696120 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4831,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:37.696602 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling MajorDeltaCompactionOp(d63e6433be2c40a9b7aada0c614b5894): perf score=1.000000
I20260812 06:16:37.887791 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: MajorDeltaCompactionOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.191s	user 0.108s	sys 0.081s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774808,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":590,"lbm_read_time_us":13701,"lbm_reads_lt_1ms":569,"lbm_write_time_us":38061,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3968,"thread_start_us":296,"threads_started":5,"update_count":2500}
I20260812 06:16:37.888358 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894): perf score=14.095187
I20260812 06:16:37.959527 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.071s	user 0.038s	sys 0.023s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":26377,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:37.960187 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894): perf score=2.188937
I20260812 06:16:37.972257 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.012s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4964,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:37.972705 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling MajorDeltaCompactionOp(d63e6433be2c40a9b7aada0c614b5894): perf score=1.000000
I20260812 06:16:38.180410 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: MajorDeltaCompactionOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.208s	user 0.126s	sys 0.072s 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":1278,"lbm_read_time_us":14168,"lbm_reads_lt_1ms":572,"lbm_write_time_us":38156,"lbm_writes_lt_1ms":543,"mutex_wait_us":438,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2500}
I20260812 06:16:38.181133 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894): perf score=14.095187
I20260812 06:16:38.231592 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.050s	user 0.035s	sys 0.012s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":24222,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:38.232162 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894): perf score=2.188937
I20260812 06:16:38.246014 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.014s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5975,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:38.246613 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling MajorDeltaCompactionOp(d63e6433be2c40a9b7aada0c614b5894): perf score=1.000000
I20260812 06:16:38.436368 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: MajorDeltaCompactionOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.190s	user 0.119s	sys 0.066s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":129,"lbm_read_time_us":12652,"lbm_reads_lt_1ms":564,"lbm_write_time_us":33444,"lbm_writes_lt_1ms":543,"mutex_wait_us":41,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":22016,"update_count":2500}
I20260812 06:16:38.437014 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894): perf score=14.095187
I20260812 06:16:38.487068 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.050s	user 0.038s	sys 0.009s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22841,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:38.487591 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894): perf score=2.188937
I20260812 06:16:38.500694 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.013s	user 0.009s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5007,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:38.501232 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling MajorDeltaCompactionOp(d63e6433be2c40a9b7aada0c614b5894): perf score=1.000000
I20260812 06:16:38.687312 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: MajorDeltaCompactionOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.186s	user 0.137s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":160,"lbm_read_time_us":10989,"lbm_reads_lt_1ms":572,"lbm_write_time_us":40211,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":17280,"update_count":2500}
I20260812 06:16:38.688004 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894): perf score=14.095187
I20260812 06:16:38.740886 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.053s	user 0.034s	sys 0.009s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":20792,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:38.741365 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894): perf score=2.188937
I20260812 06:16:38.753666 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4322,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:38.754279 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling MajorDeltaCompactionOp(d63e6433be2c40a9b7aada0c614b5894): perf score=1.000000
I20260812 06:16:38.919566 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: MajorDeltaCompactionOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.165s	user 0.103s	sys 0.049s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":371,"lbm_read_time_us":13054,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31630,"lbm_writes_lt_1ms":543,"mutex_wait_us":27,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6784,"update_count":2500}
I20260812 06:16:38.920274 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894): perf score=14.095187
I20260812 06:16:38.971822 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.051s	user 0.016s	sys 0.020s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":18514,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:38.972360 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894): perf score=2.188937
I20260812 06:16:38.984148 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4242,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:38.984643 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling FlushMRSOp(d63e6433be2c40a9b7aada0c614b5894): perf score=1.000000
I20260812 06:16:39.016533 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: FlushMRSOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.032s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":56,"dirs.run_cpu_time_us":262,"dirs.run_wall_time_us":1474,"drs_written":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1930,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:16:39.017241 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling LogGCOp(d63e6433be2c40a9b7aada0c614b5894): free 120553371 bytes of WAL
I20260812 06:16:39.017529 30581 log_reader.cc:385] T d63e6433be2c40a9b7aada0c614b5894: removed 12 log segments from log reader
I20260812 06:16:39.017590 30581 log.cc:1079] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/d63e6433be2c40a9b7aada0c614b5894/wal-000000003 (ops 11-15)
I20260812 06:16:39.017632 30581 log.cc:1079] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/d63e6433be2c40a9b7aada0c614b5894/wal-000000004 (ops 16-20)
I20260812 06:16:39.017663 30581 log.cc:1079] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/d63e6433be2c40a9b7aada0c614b5894/wal-000000005 (ops 21-24)
I20260812 06:16:39.017685 30581 log.cc:1079] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/d63e6433be2c40a9b7aada0c614b5894/wal-000000006 (ops 25-29)
I20260812 06:16:39.017707 30581 log.cc:1079] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/d63e6433be2c40a9b7aada0c614b5894/wal-000000007 (ops 30-34)
I20260812 06:16:39.017740 30581 log.cc:1079] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/d63e6433be2c40a9b7aada0c614b5894/wal-000000008 (ops 35-39)
I20260812 06:16:39.017774 30581 log.cc:1079] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/d63e6433be2c40a9b7aada0c614b5894/wal-000000009 (ops 40-44)
I20260812 06:16:39.017804 30581 log.cc:1079] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/d63e6433be2c40a9b7aada0c614b5894/wal-000000010 (ops 45-48)
I20260812 06:16:39.017833 30581 log.cc:1079] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/d63e6433be2c40a9b7aada0c614b5894/wal-000000011 (ops 49-53)
I20260812 06:16:39.017860 30581 log.cc:1079] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/d63e6433be2c40a9b7aada0c614b5894/wal-000000012 (ops 54-58)
I20260812 06:16:39.017889 30581 log.cc:1079] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/d63e6433be2c40a9b7aada0c614b5894/wal-000000013 (ops 59-63)
I20260812 06:16:39.017923 30581 log.cc:1079] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/d63e6433be2c40a9b7aada0c614b5894/wal-000000014 (ops 64-68)
I20260812 06:16:39.050146 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: LogGCOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.033s	user 0.003s	sys 0.027s Metrics: {}
I20260812 06:16:39.050668 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894): perf score=3.181125
I20260812 06:16:39.064028 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.013s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4471879,"delete_count":0,"lbm_write_time_us":4717,"lbm_writes_lt_1ms":112,"reinsert_count":0,"update_count":545}
I20260812 06:16:39.064594 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894): perf score=2.188937
I20260812 06:16:39.074517 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.010s	user 0.005s	sys 0.003s Metrics: {"bytes_written":3733433,"delete_count":0,"lbm_write_time_us":3888,"lbm_writes_lt_1ms":94,"reinsert_count":0,"update_count":455}
I20260812 06:16:39.074965 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling MajorDeltaCompactionOp(d63e6433be2c40a9b7aada0c614b5894): perf score=1.000000
I20260812 06:16:39.314320 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: MajorDeltaCompactionOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.239s	user 0.158s	sys 0.075s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979743,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":263,"lbm_read_time_us":17442,"lbm_reads_lt_1ms":774,"lbm_write_time_us":39291,"lbm_writes_lt_1ms":743,"mutex_wait_us":27,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":19712,"thread_start_us":76,"threads_started":1,"update_count":3500}
I20260812 06:16:39.314921 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894): perf score=18.063937
I20260812 06:16:39.396924 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.082s	user 0.038s	sys 0.043s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":31331,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:16:39.397576 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894): perf score=2.188937
I20260812 06:16:39.416275 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.019s	user 0.014s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6951,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:39.416776 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling MajorDeltaCompactionOp(d63e6433be2c40a9b7aada0c614b5894): perf score=1.000000
I20260812 06:16:39.652554 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: MajorDeltaCompactionOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.236s	user 0.138s	sys 0.085s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877104,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":395,"lbm_read_time_us":15471,"lbm_reads_lt_1ms":672,"lbm_write_time_us":36158,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":3000}
I20260812 06:16:39.653221 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894): perf score=18.063937
I20260812 06:16:39.734289 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.081s	user 0.061s	sys 0.004s Metrics: {"bytes_written":20512405,"delete_count":0,"lbm_write_time_us":30528,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:16:39.734786 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894): perf score=2.188937
I20260812 06:16:39.746397 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4083,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:39.746939 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling MajorDeltaCompactionOp(d63e6433be2c40a9b7aada0c614b5894): perf score=1.000000
I20260812 06:16:39.955804 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: MajorDeltaCompactionOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.209s	user 0.144s	sys 0.064s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877192,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":873,"lbm_read_time_us":15583,"lbm_reads_lt_1ms":672,"lbm_write_time_us":35173,"lbm_writes_lt_1ms":643,"mutex_wait_us":433,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7424,"update_count":3000}
I20260812 06:16:39.956700 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling UndoDeltaBlockGCOp(d63e6433be2c40a9b7aada0c614b5894): 472 bytes on disk
I20260812 06:16:39.957219 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: UndoDeltaBlockGCOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4}
I20260812 06:16:39.957984 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894): perf score=14.095187
I20260812 06:16:40.003822 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.046s	user 0.028s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20980,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:40.004391 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894): perf score=2.188937
I20260812 06:16:40.015156 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4281,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:40.015604 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling MajorDeltaCompactionOp(d63e6433be2c40a9b7aada0c614b5894): perf score=1.000000
I20260812 06:16:40.195264 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: MajorDeltaCompactionOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.179s	user 0.142s	sys 0.037s 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":442,"lbm_read_time_us":13101,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31492,"lbm_writes_lt_1ms":543,"mutex_wait_us":85,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3712,"update_count":2500}
I20260812 06:16:40.196147 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894): perf score=14.095187
I20260812 06:16:40.252365 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.056s	user 0.028s	sys 0.028s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20059,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:40.252959 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894): perf score=2.188937
I20260812 06:16:40.263965 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4274,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:40.264516 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling MajorDeltaCompactionOp(d63e6433be2c40a9b7aada0c614b5894): perf score=1.000000
I20260812 06:16:40.451983 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: MajorDeltaCompactionOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.187s	user 0.143s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":186,"lbm_read_time_us":13908,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32557,"lbm_writes_lt_1ms":543,"mutex_wait_us":72,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3072,"update_count":2500}
I20260812 06:16:40.453150 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894): perf score=11.118625
I20260812 06:16:40.507683 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.054s	user 0.038s	sys 0.011s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17702,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:16:40.508713 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894): perf score=2.188937
I20260812 06:16:40.525187 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.016s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4277,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:40.525681 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894): perf score=2.188937
I20260812 06:16:40.535458 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.010s	user 0.007s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3731,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:40.536320 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling FlushMRSOp(d63e6433be2c40a9b7aada0c614b5894): perf score=1.000000
I20260812 06:16:40.576043 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: FlushMRSOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.040s	user 0.033s	sys 0.000s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":63,"dirs.run_cpu_time_us":269,"dirs.run_wall_time_us":1482,"drs_written":1,"lbm_read_time_us":67,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1621,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:16:40.576771 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling LogGCOp(d63e6433be2c40a9b7aada0c614b5894): free 121006434 bytes of WAL
I20260812 06:16:40.577052 30581 log_reader.cc:385] T d63e6433be2c40a9b7aada0c614b5894: removed 12 log segments from log reader
I20260812 06:16:40.577112 30581 log.cc:1079] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/d63e6433be2c40a9b7aada0c614b5894/wal-000000015 (ops 69-73)
I20260812 06:16:40.577153 30581 log.cc:1079] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/d63e6433be2c40a9b7aada0c614b5894/wal-000000016 (ops 74-78)
I20260812 06:16:40.577189 30581 log.cc:1079] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/d63e6433be2c40a9b7aada0c614b5894/wal-000000017 (ops 79-83)
I20260812 06:16:40.577221 30581 log.cc:1079] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/d63e6433be2c40a9b7aada0c614b5894/wal-000000018 (ops 84-88)
I20260812 06:16:40.577250 30581 log.cc:1079] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/d63e6433be2c40a9b7aada0c614b5894/wal-000000019 (ops 89-92)
I20260812 06:16:40.577276 30581 log.cc:1079] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/d63e6433be2c40a9b7aada0c614b5894/wal-000000020 (ops 93-97)
I20260812 06:16:40.577306 30581 log.cc:1079] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/d63e6433be2c40a9b7aada0c614b5894/wal-000000021 (ops 98-102)
I20260812 06:16:40.577338 30581 log.cc:1079] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/d63e6433be2c40a9b7aada0c614b5894/wal-000000022 (ops 103-107)
I20260812 06:16:40.577365 30581 log.cc:1079] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/d63e6433be2c40a9b7aada0c614b5894/wal-000000023 (ops 108-112)
I20260812 06:16:40.577391 30581 log.cc:1079] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/d63e6433be2c40a9b7aada0c614b5894/wal-000000024 (ops 113-117)
I20260812 06:16:40.577414 30581 log.cc:1079] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/d63e6433be2c40a9b7aada0c614b5894/wal-000000025 (ops 118-122)
I20260812 06:16:40.577441 30581 log.cc:1079] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/d63e6433be2c40a9b7aada0c614b5894/wal-000000026 (ops 123-127)
I20260812 06:16:40.607275 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: LogGCOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.030s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:16:40.607888 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894): perf score=2.188937
I20260812 06:16:40.630362 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.022s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4692,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:40.630874 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894): perf score=2.188937
I20260812 06:16:40.645900 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.015s	user 0.001s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5956,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:40.646416 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling UndoDeltaBlockGCOp(d63e6433be2c40a9b7aada0c614b5894): 463 bytes on disk
I20260812 06:16:40.646828 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: UndoDeltaBlockGCOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4}
I20260812 06:16:40.647321 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling MajorDeltaCompactionOp(d63e6433be2c40a9b7aada0c614b5894): perf score=1.000000
I20260812 06:16:40.883244 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: MajorDeltaCompactionOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.236s	user 0.148s	sys 0.088s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979861,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":500,"lbm_read_time_us":16568,"lbm_reads_lt_1ms":775,"lbm_write_time_us":43816,"lbm_writes_lt_1ms":743,"mutex_wait_us":42,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":3328,"thread_start_us":77,"threads_started":1,"update_count":3500}
I20260812 06:16:40.884030 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894): perf score=18.063937
I20260812 06:16:40.948360 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.064s	user 0.035s	sys 0.029s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":29743,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:16:40.948905 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894): perf score=2.188937
I20260812 06:16:40.964461 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.015s	user 0.007s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5762,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:40.964975 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling MajorDeltaCompactionOp(d63e6433be2c40a9b7aada0c614b5894): perf score=1.000000
I20260812 06:16:41.128394 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: MajorDeltaCompactionOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.163s	user 0.123s	sys 0.040s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":117,"lbm_read_time_us":12349,"lbm_reads_lt_1ms":664,"lbm_write_time_us":34254,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6400,"update_count":3000}
I20260812 06:16:41.130432 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894): perf score=14.095187
I20260812 06:16:41.180614 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.049s	user 0.026s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22034,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:41.181133 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894): perf score=2.188937
I20260812 06:16:41.197561 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.016s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6539,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:41.198015 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling MajorDeltaCompactionOp(d63e6433be2c40a9b7aada0c614b5894): perf score=1.000000
I20260812 06:16:41.370605 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: MajorDeltaCompactionOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.172s	user 0.128s	sys 0.033s 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":1085,"lbm_read_time_us":11194,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30718,"lbm_writes_lt_1ms":543,"mutex_wait_us":381,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15744,"update_count":2500}
I20260812 06:16:41.371381 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894): perf score=14.095187
I20260812 06:16:41.417920 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.046s	user 0.020s	sys 0.024s Metrics: {"bytes_written":16409906,"delete_count":0,"lbm_write_time_us":20683,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:41.418668 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling MajorDeltaCompactionOp(d63e6433be2c40a9b7aada0c614b5894): perf score=1.000000
I20260812 06:16:41.585625 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: MajorDeltaCompactionOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.167s	user 0.115s	sys 0.044s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672162,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":960,"lbm_read_time_us":11350,"lbm_reads_lt_1ms":467,"lbm_write_time_us":26671,"lbm_writes_lt_1ms":443,"mutex_wait_us":393,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6528,"update_count":2000}
I20260812 06:16:41.586386 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894): perf score=14.095187
I20260812 06:16:41.647339 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.061s	user 0.031s	sys 0.015s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22828,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:41.647833 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894): perf score=2.188937
I20260812 06:16:41.659373 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4053,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:41.659898 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling MajorDeltaCompactionOp(d63e6433be2c40a9b7aada0c614b5894): perf score=1.000000
I20260812 06:16:41.863039 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: MajorDeltaCompactionOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.203s	user 0.127s	sys 0.067s 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":602,"lbm_read_time_us":13790,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33047,"lbm_writes_lt_1ms":543,"mutex_wait_us":294,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14208,"update_count":2500}
I20260812 06:16:41.863708 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894): perf score=14.095187
I20260812 06:16:41.918577 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.055s	user 0.035s	sys 0.012s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23893,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:41.919072 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894): perf score=2.188937
I20260812 06:16:41.932201 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.013s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4947,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:41.932777 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling MajorDeltaCompactionOp(d63e6433be2c40a9b7aada0c614b5894): perf score=1.000000
I20260812 06:16:42.096886 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: MajorDeltaCompactionOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.164s	user 0.117s	sys 0.045s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":216,"lbm_read_time_us":10080,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32133,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":24704,"update_count":2500}
I20260812 06:16:42.097841 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894): perf score=14.095187
I20260812 06:16:42.151199 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.053s	user 0.022s	sys 0.028s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":25287,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:16:42.151779 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894): perf score=2.188937
I20260812 06:16:42.167237 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4661,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:42.167899 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling FlushMRSOp(d63e6433be2c40a9b7aada0c614b5894): perf score=1.000000
I20260812 06:16:42.223807 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: FlushMRSOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.056s	user 0.036s	sys 0.000s Metrics: {"bytes_written":1357582,"cfile_init":1,"dirs.queue_time_us":66,"dirs.run_cpu_time_us":214,"dirs.run_wall_time_us":1215,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1863,"lbm_writes_lt_1ms":44,"peak_mem_usage":0,"rows_written":33}
I20260812 06:16:42.224588 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling LogGCOp(d63e6433be2c40a9b7aada0c614b5894): free 132571585 bytes of WAL
I20260812 06:16:42.224833 30581 log_reader.cc:385] T d63e6433be2c40a9b7aada0c614b5894: removed 13 log segments from log reader
I20260812 06:16:42.224881 30581 log.cc:1079] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/d63e6433be2c40a9b7aada0c614b5894/wal-000000027 (ops 128-132)
I20260812 06:16:42.224912 30581 log.cc:1079] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/d63e6433be2c40a9b7aada0c614b5894/wal-000000028 (ops 133-137)
I20260812 06:16:42.224987 30581 log.cc:1079] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/d63e6433be2c40a9b7aada0c614b5894/wal-000000029 (ops 138-142)
I20260812 06:16:42.225030 30581 log.cc:1079] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/d63e6433be2c40a9b7aada0c614b5894/wal-000000030 (ops 143-146)
I20260812 06:16:42.225070 30581 log.cc:1079] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/d63e6433be2c40a9b7aada0c614b5894/wal-000000031 (ops 147-151)
I20260812 06:16:42.225116 30581 log.cc:1079] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/d63e6433be2c40a9b7aada0c614b5894/wal-000000032 (ops 152-156)
I20260812 06:16:42.225152 30581 log.cc:1079] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/d63e6433be2c40a9b7aada0c614b5894/wal-000000033 (ops 157-161)
I20260812 06:16:42.225209 30581 log.cc:1079] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/d63e6433be2c40a9b7aada0c614b5894/wal-000000034 (ops 162-166)
I20260812 06:16:42.225236 30581 log.cc:1079] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/d63e6433be2c40a9b7aada0c614b5894/wal-000000035 (ops 167-171)
I20260812 06:16:42.225278 30581 log.cc:1079] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/d63e6433be2c40a9b7aada0c614b5894/wal-000000036 (ops 172-176)
I20260812 06:16:42.225318 30581 log.cc:1079] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/d63e6433be2c40a9b7aada0c614b5894/wal-000000037 (ops 177-181)
I20260812 06:16:42.225358 30581 log.cc:1079] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/d63e6433be2c40a9b7aada0c614b5894/wal-000000038 (ops 182-186)
I20260812 06:16:42.225396 30581 log.cc:1079] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/d63e6433be2c40a9b7aada0c614b5894/wal-000000039 (ops 187-190)
I20260812 06:16:42.258389 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: LogGCOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.034s	user 0.000s	sys 0.031s Metrics: {}
I20260812 06:16:42.259027 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894): perf score=6.157687
I20260812 06:16:42.280400 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.021s	user 0.017s	sys 0.004s Metrics: {"bytes_written":8205077,"delete_count":0,"lbm_write_time_us":9351,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:42.280895 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling LogGCOp(d63e6433be2c40a9b7aada0c614b5894): free 8767088 bytes of WAL
I20260812 06:16:42.281103 30581 log_reader.cc:385] T d63e6433be2c40a9b7aada0c614b5894: removed 1 log segments from log reader
I20260812 06:16:42.281148 30581 log.cc:1079] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456: Deleting log segment in path: /tmp/dist-test-taskJMRVc_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515391260141-30248-0/minicluster-data/ts-0-root/wals/d63e6433be2c40a9b7aada0c614b5894/wal-000000040 (ops 191-195)
I20260812 06:16:42.282938 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: LogGCOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:16:42.283236 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling UndoDeltaBlockGCOp(d63e6433be2c40a9b7aada0c614b5894): 507 bytes on disk
I20260812 06:16:42.283618 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: UndoDeltaBlockGCOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:16:42.284188 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894): perf score=2.188937
I20260812 06:16:42.296662 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: FlushDeltaMemStoresOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.012s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4458,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:42.297200 30661 maintenance_manager.cc:419] P 19ed44496a304642818732e0e08e5456: Scheduling MajorDeltaCompactionOp(d63e6433be2c40a9b7aada0c614b5894): perf score=1.000000
I20260812 06:16:42.375232 30248 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.050s	user 1.866s	sys 0.190s
I20260812 06:16:42.482896 30248 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.107s	user 0.000s	sys 0.000s
I20260812 06:16:42.483410 30248 tablet_server.cc:179] TabletServer@127.29.138.1:0 shutting down...
I20260812 06:16:42.541419 30581 maintenance_manager.cc:643] P 19ed44496a304642818732e0e08e5456: MajorDeltaCompactionOp(d63e6433be2c40a9b7aada0c614b5894) complete. Timing: real 0.244s	user 0.144s	sys 0.099s Metrics: {"cfile_cache_miss":834,"cfile_cache_miss_bytes":37082159,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":842,"lbm_read_time_us":17757,"lbm_reads_lt_1ms":862,"lbm_write_time_us":40459,"lbm_writes_lt_1ms":843,"mutex_wait_us":105,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":3200,"thread_start_us":81,"threads_started":1,"update_count":4000}
I20260812 06:16:42.542647 30248 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:16:42.542969 30248 tablet_replica.cc:333] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456: stopping tablet replica
I20260812 06:16:42.543115 30248 raft_consensus.cc:2243] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:42.543254 30248 raft_consensus.cc:2272] T d63e6433be2c40a9b7aada0c614b5894 P 19ed44496a304642818732e0e08e5456 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:42.558761 30248 tablet_server.cc:196] TabletServer@127.29.138.1:0 shutdown complete.
I20260812 06:16:42.613274 30248 master.cc:562] Master@127.29.138.62:33663 shutting down...
I20260812 06:16:42.616767 30248 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 93e610442f4046129d48c296a825c2d4 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:42.616938 30248 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 93e610442f4046129d48c296a825c2d4 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:42.616992 30248 tablet_replica.cc:333] T 00000000000000000000000000000000 P 93e610442f4046129d48c296a825c2d4: stopping tablet replica
I20260812 06:16:42.629315 30248 master.cc:584] Master@127.29.138.62:33663 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5599 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11450 ms total)

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