[==========] 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:48.947013 10382 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.10.35.190:38841
I20260812 06:16:48.948047 10382 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:48.948650 10382 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:48.955101 10393 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:48.955129 10396 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:48.955403 10394 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:48.955459 10382 server_base.cc:1061] running on GCE node
I20260812 06:16:48.955950 10382 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:48.956116 10382 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:48.956182 10382 hybrid_clock.cc:648] HybridClock initialized: now 1786515408956178 us; error 0 us; skew 500 ppm
I20260812 06:16:48.958037 10382 webserver.cc:533] Webserver started at http://127.10.35.190:44349/ using document root <none> and password file <none>
I20260812 06:16:48.958626 10382 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:48.958714 10382 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:48.959005 10382 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:48.960762 10382 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515408936392-10382-0/minicluster-data/master-0-root/instance:
uuid: "f9ad29d5bfc74edf8d9f32ec63096c52"
format_stamp: "Formatted at 2026-08-12 06:16:48 on dist-test-slave-92m1"
I20260812 06:16:48.964295 10382 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.003s	sys 0.001s
I20260812 06:16:48.966408 10405 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:48.967423 10382 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.001s
I20260812 06:16:48.967559 10382 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515408936392-10382-0/minicluster-data/master-0-root
uuid: "f9ad29d5bfc74edf8d9f32ec63096c52"
format_stamp: "Formatted at 2026-08-12 06:16:48 on dist-test-slave-92m1"
I20260812 06:16:48.967669 10382 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515408936392-10382-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515408936392-10382-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515408936392-10382-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:48.978832 10382 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:48.979591 10382 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:48.979789 10382 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:48.988065 10382 rpc_server.cc:307] RPC server started. Bound to: 127.10.35.190:38841
I20260812 06:16:48.988070 10494 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.10.35.190:38841 every 8 connection(s)
I20260812 06:16:48.990307 10495 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:48.995704 10495 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P f9ad29d5bfc74edf8d9f32ec63096c52: Bootstrap starting.
I20260812 06:16:48.997968 10495 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P f9ad29d5bfc74edf8d9f32ec63096c52: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:48.998802 10495 log.cc:826] T 00000000000000000000000000000000 P f9ad29d5bfc74edf8d9f32ec63096c52: Log is configured to *not* fsync() on all Append() calls
I20260812 06:16:49.000425 10495 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P f9ad29d5bfc74edf8d9f32ec63096c52: No bootstrap required, opened a new log
I20260812 06:16:49.003075 10495 raft_consensus.cc:359] T 00000000000000000000000000000000 P f9ad29d5bfc74edf8d9f32ec63096c52 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f9ad29d5bfc74edf8d9f32ec63096c52" member_type: VOTER }
I20260812 06:16:49.003248 10495 raft_consensus.cc:385] T 00000000000000000000000000000000 P f9ad29d5bfc74edf8d9f32ec63096c52 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:49.003291 10495 raft_consensus.cc:740] T 00000000000000000000000000000000 P f9ad29d5bfc74edf8d9f32ec63096c52 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: f9ad29d5bfc74edf8d9f32ec63096c52, State: Initialized, Role: FOLLOWER
I20260812 06:16:49.003886 10495 consensus_queue.cc:260] T 00000000000000000000000000000000 P f9ad29d5bfc74edf8d9f32ec63096c52 [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: "f9ad29d5bfc74edf8d9f32ec63096c52" member_type: VOTER }
I20260812 06:16:49.004032 10495 raft_consensus.cc:399] T 00000000000000000000000000000000 P f9ad29d5bfc74edf8d9f32ec63096c52 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:49.004074 10495 raft_consensus.cc:493] T 00000000000000000000000000000000 P f9ad29d5bfc74edf8d9f32ec63096c52 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:49.004165 10495 raft_consensus.cc:3060] T 00000000000000000000000000000000 P f9ad29d5bfc74edf8d9f32ec63096c52 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:49.004874 10495 raft_consensus.cc:515] T 00000000000000000000000000000000 P f9ad29d5bfc74edf8d9f32ec63096c52 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f9ad29d5bfc74edf8d9f32ec63096c52" member_type: VOTER }
I20260812 06:16:49.005277 10495 leader_election.cc:304] T 00000000000000000000000000000000 P f9ad29d5bfc74edf8d9f32ec63096c52 [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: f9ad29d5bfc74edf8d9f32ec63096c52; no voters: 
I20260812 06:16:49.005535 10495 leader_election.cc:290] T 00000000000000000000000000000000 P f9ad29d5bfc74edf8d9f32ec63096c52 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:49.005688 10499 raft_consensus.cc:2804] T 00000000000000000000000000000000 P f9ad29d5bfc74edf8d9f32ec63096c52 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:49.005956 10499 raft_consensus.cc:697] T 00000000000000000000000000000000 P f9ad29d5bfc74edf8d9f32ec63096c52 [term 1 LEADER]: Becoming Leader. State: Replica: f9ad29d5bfc74edf8d9f32ec63096c52, State: Running, Role: LEADER
I20260812 06:16:49.006404 10499 consensus_queue.cc:237] T 00000000000000000000000000000000 P f9ad29d5bfc74edf8d9f32ec63096c52 [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: "f9ad29d5bfc74edf8d9f32ec63096c52" member_type: VOTER }
I20260812 06:16:49.006489 10495 sys_catalog.cc:565] T 00000000000000000000000000000000 P f9ad29d5bfc74edf8d9f32ec63096c52 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:49.008409 10504 sys_catalog.cc:455] T 00000000000000000000000000000000 P f9ad29d5bfc74edf8d9f32ec63096c52 [sys.catalog]: SysCatalogTable state changed. Reason: New leader f9ad29d5bfc74edf8d9f32ec63096c52. Latest consensus state: current_term: 1 leader_uuid: "f9ad29d5bfc74edf8d9f32ec63096c52" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f9ad29d5bfc74edf8d9f32ec63096c52" member_type: VOTER } }
I20260812 06:16:49.008539 10504 sys_catalog.cc:458] T 00000000000000000000000000000000 P f9ad29d5bfc74edf8d9f32ec63096c52 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:49.008427 10503 sys_catalog.cc:455] T 00000000000000000000000000000000 P f9ad29d5bfc74edf8d9f32ec63096c52 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "f9ad29d5bfc74edf8d9f32ec63096c52" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f9ad29d5bfc74edf8d9f32ec63096c52" member_type: VOTER } }
I20260812 06:16:49.008832 10503 sys_catalog.cc:458] T 00000000000000000000000000000000 P f9ad29d5bfc74edf8d9f32ec63096c52 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:49.008880 10524 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:49.008898 10382 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:16:49.010959 10524 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:49.015153 10524 catalog_manager.cc:1383] Generated new cluster ID: c1e34a4438cf4060a47b107073582450
I20260812 06:16:49.015247 10524 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:49.031286 10524 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:49.032501 10524 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:49.044206 10524 catalog_manager.cc:6092] T 00000000000000000000000000000000 P f9ad29d5bfc74edf8d9f32ec63096c52: Generated new TSK 0
I20260812 06:16:49.045022 10524 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:49.073820 10382 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:49.076900 10532 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:49.077047 10382 server_base.cc:1061] running on GCE node
W20260812 06:16:49.076932 10531 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:49.076952 10536 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:49.077437 10382 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:49.077510 10382 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:49.077548 10382 hybrid_clock.cc:648] HybridClock initialized: now 1786515409077545 us; error 0 us; skew 500 ppm
I20260812 06:16:49.078572 10382 webserver.cc:533] Webserver started at http://127.10.35.129:37661/ using document root <none> and password file <none>
I20260812 06:16:49.078765 10382 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:49.078840 10382 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:49.078919 10382 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:49.079425 10382 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515408936392-10382-0/minicluster-data/ts-0-root/instance:
uuid: "953ddfd39e104b22905c34ab335efee8"
format_stamp: "Formatted at 2026-08-12 06:16:49 on dist-test-slave-92m1"
I20260812 06:16:49.081036 10382 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:16:49.082070 10543 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:49.082315 10382 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:49.082388 10382 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515408936392-10382-0/minicluster-data/ts-0-root
uuid: "953ddfd39e104b22905c34ab335efee8"
format_stamp: "Formatted at 2026-08-12 06:16:49 on dist-test-slave-92m1"
I20260812 06:16:49.082480 10382 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515408936392-10382-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515408936392-10382-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515408936392-10382-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:49.097841 10382 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:49.098302 10382 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:49.098840 10382 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:49.099848 10382 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:49.099901 10382 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:49.099974 10382 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:49.100015 10382 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:49.106660 10382 rpc_server.cc:307] RPC server started. Bound to: 127.10.35.129:46393
I20260812 06:16:49.106745 10642 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.10.35.129:46393 every 8 connection(s)
I20260812 06:16:49.117087 10644 heartbeater.cc:344] Connected to a master server at 127.10.35.190:38841
I20260812 06:16:49.117331 10644 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:49.117791 10644 heartbeater.cc:507] Master 127.10.35.190:38841 requested a full tablet report, sending...
I20260812 06:16:49.119489 10428 ts_manager.cc:194] Registered new tserver with Master: 953ddfd39e104b22905c34ab335efee8 (127.10.35.129:46393)
I20260812 06:16:49.119658 10382 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012337013s
I20260812 06:16:49.121179 10428 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:60976
I20260812 06:16:49.129755 10428 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:60984:
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:49.144253 10581 tablet_service.cc:1511] Processing CreateTablet for tablet daf98bb8974547c687f7606d45e5144f (DEFAULT_TABLE table=heavy-update-compaction-test [id=0d95a938054646a9bfdf346614324e93]), partition=
I20260812 06:16:49.144740 10581 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet daf98bb8974547c687f7606d45e5144f. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:49.147845 10657 tablet_bootstrap.cc:492] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8: Bootstrap starting.
I20260812 06:16:49.149084 10657 tablet_bootstrap.cc:654] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:49.150409 10657 tablet_bootstrap.cc:492] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8: No bootstrap required, opened a new log
I20260812 06:16:49.150540 10657 ts_tablet_manager.cc:1403] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:16:49.151057 10657 raft_consensus.cc:359] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "953ddfd39e104b22905c34ab335efee8" member_type: VOTER last_known_addr { host: "127.10.35.129" port: 46393 } }
I20260812 06:16:49.151186 10657 raft_consensus.cc:385] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:49.151268 10657 raft_consensus.cc:740] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 953ddfd39e104b22905c34ab335efee8, State: Initialized, Role: FOLLOWER
I20260812 06:16:49.151420 10657 consensus_queue.cc:260] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8 [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: "953ddfd39e104b22905c34ab335efee8" member_type: VOTER last_known_addr { host: "127.10.35.129" port: 46393 } }
I20260812 06:16:49.151539 10657 raft_consensus.cc:399] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:49.151618 10657 raft_consensus.cc:493] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:49.151678 10657 raft_consensus.cc:3060] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:49.152856 10657 raft_consensus.cc:515] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "953ddfd39e104b22905c34ab335efee8" member_type: VOTER last_known_addr { host: "127.10.35.129" port: 46393 } }
I20260812 06:16:49.153024 10657 leader_election.cc:304] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8 [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: 953ddfd39e104b22905c34ab335efee8; no voters: 
I20260812 06:16:49.153275 10657 leader_election.cc:290] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:49.153527 10663 raft_consensus.cc:2804] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:49.153756 10663 raft_consensus.cc:697] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8 [term 1 LEADER]: Becoming Leader. State: Replica: 953ddfd39e104b22905c34ab335efee8, State: Running, Role: LEADER
I20260812 06:16:49.153757 10657 ts_tablet_manager.cc:1434] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:16:49.153985 10644 heartbeater.cc:499] Master 127.10.35.190:38841 was elected leader, sending a full tablet report...
I20260812 06:16:49.153990 10663 consensus_queue.cc:237] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8 [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: "953ddfd39e104b22905c34ab335efee8" member_type: VOTER last_known_addr { host: "127.10.35.129" port: 46393 } }
I20260812 06:16:49.157205 10428 catalog_manager.cc:5719] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8 reported cstate change: term changed from 0 to 1, leader changed from <none> to 953ddfd39e104b22905c34ab335efee8 (127.10.35.129). New cstate: current_term: 1 leader_uuid: "953ddfd39e104b22905c34ab335efee8" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "953ddfd39e104b22905c34ab335efee8" member_type: VOTER last_known_addr { host: "127.10.35.129" port: 46393 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:49.221989 10382 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.057s	user 0.020s	sys 0.006s
I20260812 06:16:49.357722 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling FlushMRSOp(daf98bb8974547c687f7606d45e5144f): perf score=19.054940
I20260812 06:16:49.540108 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: FlushMRSOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.182s	user 0.140s	sys 0.036s Metrics: {"bytes_written":12307490,"cfile_init":1,"compiler_manager_pool.queue_time_us":203,"delete_count":0,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":201,"dirs.run_wall_time_us":990,"drs_written":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4,"lbm_write_time_us":45116,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":113,"threads_started":1,"update_count":1500}
I20260812 06:16:49.541286 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling LogGCOp(daf98bb8974547c687f7606d45e5144f): free 20743880 bytes of WAL
I20260812 06:16:49.541563 10551 log_reader.cc:385] T daf98bb8974547c687f7606d45e5144f: removed 2 log segments from log reader
I20260812 06:16:49.541615 10551 log.cc:1079] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/daf98bb8974547c687f7606d45e5144f/wal-000000001 (ops 1-6)
I20260812 06:16:49.541666 10551 log.cc:1079] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/daf98bb8974547c687f7606d45e5144f/wal-000000002 (ops 7-11)
I20260812 06:16:49.547619 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: LogGCOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.006s	user 0.000s	sys 0.006s Metrics: {}
I20260812 06:16:49.547987 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling UndoDeltaBlockGCOp(daf98bb8974547c687f7606d45e5144f): 16411393 bytes on disk
I20260812 06:16:49.548589 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: UndoDeltaBlockGCOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4}
I20260812 06:16:49.549026 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f): perf score=2.188937
I20260812 06:16:49.569998 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.021s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6520,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:49.570482 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling MajorDeltaCompactionOp(daf98bb8974547c687f7606d45e5144f): perf score=1.000000
I20260812 06:16:49.710347 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: MajorDeltaCompactionOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.140s	user 0.108s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":292,"lbm_read_time_us":6832,"lbm_reads_lt_1ms":460,"lbm_write_time_us":24607,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4352,"thread_start_us":304,"threads_started":5,"update_count":2000}
I20260812 06:16:49.710952 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f): perf score=10.126437
I20260812 06:16:49.749415 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.038s	user 0.018s	sys 0.016s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":16328,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:49.749879 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f): perf score=2.188937
I20260812 06:16:49.760649 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.011s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4253,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:49.761068 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling MajorDeltaCompactionOp(daf98bb8974547c687f7606d45e5144f): perf score=1.000000
I20260812 06:16:49.895061 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: MajorDeltaCompactionOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.134s	user 0.122s	sys 0.012s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":212,"lbm_read_time_us":7966,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25666,"lbm_writes_lt_1ms":443,"mutex_wait_us":27,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12032,"update_count":2000}
I20260812 06:16:49.895710 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f): perf score=10.126437
I20260812 06:16:49.941885 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.046s	user 0.021s	sys 0.011s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15069,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:49.942404 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f): perf score=2.188937
I20260812 06:16:49.953778 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4093,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:49.954352 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling MajorDeltaCompactionOp(daf98bb8974547c687f7606d45e5144f): perf score=1.000000
I20260812 06:16:50.078616 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: MajorDeltaCompactionOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.124s	user 0.096s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":453,"lbm_read_time_us":9035,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22939,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4864,"update_count":2000}
I20260812 06:16:50.079347 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f): perf score=10.126437
I20260812 06:16:50.125386 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.046s	user 0.028s	sys 0.016s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":17014,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:50.125994 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f): perf score=2.188937
I20260812 06:16:50.137355 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4424,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:50.138047 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling MajorDeltaCompactionOp(daf98bb8974547c687f7606d45e5144f): perf score=1.000000
I20260812 06:16:50.286170 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: MajorDeltaCompactionOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.148s	user 0.099s	sys 0.048s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672275,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":770,"lbm_read_time_us":12217,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22586,"lbm_writes_lt_1ms":443,"mutex_wait_us":337,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2000}
I20260812 06:16:50.286793 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f): perf score=10.126437
I20260812 06:16:50.319542 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.033s	user 0.021s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13733,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:50.320065 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f): perf score=2.188937
I20260812 06:16:50.335894 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.016s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6030,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:50.336480 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling MajorDeltaCompactionOp(daf98bb8974547c687f7606d45e5144f): perf score=1.000000
I20260812 06:16:50.465188 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: MajorDeltaCompactionOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.128s	user 0.110s	sys 0.018s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":177,"lbm_read_time_us":8515,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25118,"lbm_writes_lt_1ms":443,"mutex_wait_us":30,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8320,"update_count":2000}
I20260812 06:16:50.465975 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f): perf score=10.126437
I20260812 06:16:50.511157 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.045s	user 0.025s	sys 0.009s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16152,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:50.511659 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f): perf score=2.188937
I20260812 06:16:50.523020 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.011s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4175,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:50.523687 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling MajorDeltaCompactionOp(daf98bb8974547c687f7606d45e5144f): perf score=1.000000
I20260812 06:16:50.658188 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: MajorDeltaCompactionOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.134s	user 0.109s	sys 0.026s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":388,"lbm_read_time_us":9804,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27826,"lbm_writes_lt_1ms":443,"mutex_wait_us":51,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":18688,"update_count":2000}
I20260812 06:16:50.658849 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f): perf score=10.126437
I20260812 06:16:50.699389 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.040s	user 0.032s	sys 0.004s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15345,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:50.699908 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f): perf score=2.188937
I20260812 06:16:50.710696 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4101,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:50.711376 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling FlushMRSOp(daf98bb8974547c687f7606d45e5144f): perf score=1.000000
I20260812 06:16:50.743494 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: FlushMRSOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.032s	user 0.031s	sys 0.001s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":74,"dirs.run_cpu_time_us":284,"dirs.run_wall_time_us":1334,"drs_written":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1835,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:16:50.744282 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling LogGCOp(daf98bb8974547c687f7606d45e5144f): free 112692367 bytes of WAL
I20260812 06:16:50.744526 10551 log_reader.cc:385] T daf98bb8974547c687f7606d45e5144f: removed 11 log segments from log reader
I20260812 06:16:50.744573 10551 log.cc:1079] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/daf98bb8974547c687f7606d45e5144f/wal-000000003 (ops 12-16)
I20260812 06:16:50.744602 10551 log.cc:1079] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/daf98bb8974547c687f7606d45e5144f/wal-000000004 (ops 17-21)
I20260812 06:16:50.744669 10551 log.cc:1079] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/daf98bb8974547c687f7606d45e5144f/wal-000000005 (ops 22-26)
I20260812 06:16:50.744724 10551 log.cc:1079] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/daf98bb8974547c687f7606d45e5144f/wal-000000006 (ops 27-31)
I20260812 06:16:50.744765 10551 log.cc:1079] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/daf98bb8974547c687f7606d45e5144f/wal-000000007 (ops 32-36)
I20260812 06:16:50.744820 10551 log.cc:1079] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/daf98bb8974547c687f7606d45e5144f/wal-000000008 (ops 37-41)
I20260812 06:16:50.744863 10551 log.cc:1079] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/daf98bb8974547c687f7606d45e5144f/wal-000000009 (ops 42-46)
I20260812 06:16:50.744899 10551 log.cc:1079] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/daf98bb8974547c687f7606d45e5144f/wal-000000010 (ops 47-51)
I20260812 06:16:50.744940 10551 log.cc:1079] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/daf98bb8974547c687f7606d45e5144f/wal-000000011 (ops 52-56)
I20260812 06:16:50.744979 10551 log.cc:1079] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/daf98bb8974547c687f7606d45e5144f/wal-000000012 (ops 57-61)
I20260812 06:16:50.745019 10551 log.cc:1079] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/daf98bb8974547c687f7606d45e5144f/wal-000000013 (ops 62-66)
I20260812 06:16:50.769713 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: LogGCOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.025s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:16:50.770108 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling UndoDeltaBlockGCOp(daf98bb8974547c687f7606d45e5144f): 448 bytes on disk
I20260812 06:16:50.770550 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: UndoDeltaBlockGCOp(daf98bb8974547c687f7606d45e5144f) 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:50.770998 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f): perf score=2.188937
I20260812 06:16:50.791590 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.020s	user 0.016s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6411,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:50.791994 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f): perf score=2.188937
I20260812 06:16:50.802011 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.010s	user 0.005s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3989,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:50.802433 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling MajorDeltaCompactionOp(daf98bb8974547c687f7606d45e5144f): perf score=1.000000
I20260812 06:16:50.970968 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: MajorDeltaCompactionOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.168s	user 0.152s	sys 0.012s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877339,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":805,"lbm_read_time_us":10445,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34464,"lbm_writes_lt_1ms":643,"mutex_wait_us":44,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2048,"thread_start_us":76,"threads_started":1,"update_count":3000}
I20260812 06:16:50.971911 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f): perf score=14.095187
I20260812 06:16:51.018469 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.045s	user 0.025s	sys 0.016s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":19296,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:51.018965 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f): perf score=2.188937
I20260812 06:16:51.030530 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4598,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:51.031019 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling MajorDeltaCompactionOp(daf98bb8974547c687f7606d45e5144f): perf score=1.000000
I20260812 06:16:51.190737 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: MajorDeltaCompactionOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.160s	user 0.116s	sys 0.032s 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":251,"lbm_read_time_us":9936,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32037,"lbm_writes_lt_1ms":543,"mutex_wait_us":79,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2500}
I20260812 06:16:51.191567 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f): perf score=14.095187
I20260812 06:16:51.241525 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.050s	user 0.035s	sys 0.012s Metrics: {"bytes_written":16409906,"delete_count":0,"lbm_write_time_us":21771,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:51.242058 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling MajorDeltaCompactionOp(daf98bb8974547c687f7606d45e5144f): perf score=1.000000
I20260812 06:16:51.392648 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: MajorDeltaCompactionOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.150s	user 0.099s	sys 0.042s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672162,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":228,"lbm_read_time_us":10433,"lbm_reads_lt_1ms":463,"lbm_write_time_us":23777,"lbm_writes_lt_1ms":443,"mutex_wait_us":69,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14720,"update_count":2000}
I20260812 06:16:51.393278 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f): perf score=14.095187
I20260812 06:16:51.450088 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.055s	user 0.020s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18475,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:51.450738 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f): perf score=2.188937
I20260812 06:16:51.467916 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.017s	user 0.013s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6418,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:51.468626 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling MajorDeltaCompactionOp(daf98bb8974547c687f7606d45e5144f): perf score=1.000000
I20260812 06:16:51.665087 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: MajorDeltaCompactionOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.196s	user 0.130s	sys 0.059s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":522,"lbm_read_time_us":14203,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34461,"lbm_writes_lt_1ms":543,"mutex_wait_us":50,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7168,"update_count":2500}
I20260812 06:16:51.665711 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f): perf score=14.095187
I20260812 06:16:51.732446 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.067s	user 0.029s	sys 0.027s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":20317,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:51.733170 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f): perf score=2.188937
I20260812 06:16:51.750366 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.017s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6468,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:51.751034 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling MajorDeltaCompactionOp(daf98bb8974547c687f7606d45e5144f): perf score=1.000000
I20260812 06:16:51.919549 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: MajorDeltaCompactionOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.168s	user 0.116s	sys 0.049s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1180,"lbm_read_time_us":14088,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27421,"lbm_writes_lt_1ms":543,"mutex_wait_us":644,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:16:51.923305 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f): perf score=11.118625
I20260812 06:16:51.964774 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.041s	user 0.023s	sys 0.016s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":18312,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:51.965595 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f): perf score=2.188937
I20260812 06:16:51.984899 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.019s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5979,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:51.985417 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling MajorDeltaCompactionOp(daf98bb8974547c687f7606d45e5144f): perf score=1.000000
I20260812 06:16:52.115013 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: MajorDeltaCompactionOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.129s	user 0.100s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1105,"lbm_read_time_us":8951,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24205,"lbm_writes_lt_1ms":443,"mutex_wait_us":245,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":19712,"update_count":2000}
I20260812 06:16:52.115762 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f): perf score=10.126437
I20260812 06:16:52.154969 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.039s	user 0.034s	sys 0.000s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":15953,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:52.155521 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f): perf score=2.188937
I20260812 06:16:52.166937 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4194,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:52.167677 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling FlushMRSOp(daf98bb8974547c687f7606d45e5144f): perf score=1.000000
I20260812 06:16:52.198844 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: FlushMRSOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.031s	user 0.024s	sys 0.000s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":81,"dirs.run_cpu_time_us":236,"dirs.run_wall_time_us":1336,"drs_written":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1517,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:16:52.199797 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling LogGCOp(daf98bb8974547c687f7606d45e5144f): free 120553380 bytes of WAL
I20260812 06:16:52.200142 10551 log_reader.cc:385] T daf98bb8974547c687f7606d45e5144f: removed 12 log segments from log reader
I20260812 06:16:52.200212 10551 log.cc:1079] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/daf98bb8974547c687f7606d45e5144f/wal-000000014 (ops 67-70)
I20260812 06:16:52.200250 10551 log.cc:1079] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/daf98bb8974547c687f7606d45e5144f/wal-000000015 (ops 71-75)
I20260812 06:16:52.200274 10551 log.cc:1079] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/daf98bb8974547c687f7606d45e5144f/wal-000000016 (ops 76-80)
I20260812 06:16:52.200301 10551 log.cc:1079] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/daf98bb8974547c687f7606d45e5144f/wal-000000017 (ops 81-85)
I20260812 06:16:52.200340 10551 log.cc:1079] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/daf98bb8974547c687f7606d45e5144f/wal-000000018 (ops 86-90)
I20260812 06:16:52.200381 10551 log.cc:1079] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/daf98bb8974547c687f7606d45e5144f/wal-000000019 (ops 91-94)
I20260812 06:16:52.200405 10551 log.cc:1079] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/daf98bb8974547c687f7606d45e5144f/wal-000000020 (ops 95-99)
I20260812 06:16:52.200428 10551 log.cc:1079] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/daf98bb8974547c687f7606d45e5144f/wal-000000021 (ops 100-104)
I20260812 06:16:52.200459 10551 log.cc:1079] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/daf98bb8974547c687f7606d45e5144f/wal-000000022 (ops 105-109)
I20260812 06:16:52.200495 10551 log.cc:1079] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/daf98bb8974547c687f7606d45e5144f/wal-000000023 (ops 110-114)
I20260812 06:16:52.200528 10551 log.cc:1079] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/daf98bb8974547c687f7606d45e5144f/wal-000000024 (ops 115-119)
I20260812 06:16:52.200558 10551 log.cc:1079] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/daf98bb8974547c687f7606d45e5144f/wal-000000025 (ops 120-124)
I20260812 06:16:52.227897 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: LogGCOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.028s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:16:52.228539 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f): perf score=2.188937
I20260812 06:16:52.256557 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.028s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6735,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:52.257099 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling UndoDeltaBlockGCOp(daf98bb8974547c687f7606d45e5144f): 462 bytes on disk
I20260812 06:16:52.257587 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: UndoDeltaBlockGCOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:16:52.258111 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f): perf score=2.188937
I20260812 06:16:52.270093 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4293,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:52.270603 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling MajorDeltaCompactionOp(daf98bb8974547c687f7606d45e5144f): perf score=1.000000
I20260812 06:16:52.449987 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: MajorDeltaCompactionOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.179s	user 0.138s	sys 0.036s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877338,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1507,"lbm_read_time_us":13025,"lbm_reads_lt_1ms":674,"lbm_write_time_us":35794,"lbm_writes_lt_1ms":643,"mutex_wait_us":889,"peak_mem_usage":75542472,"reinsert_count":0,"thread_start_us":87,"threads_started":1,"update_count":3000}
I20260812 06:16:52.450572 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f): perf score=14.095187
I20260812 06:16:52.510545 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.060s	user 0.032s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24743,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:52.511030 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f): perf score=2.188937
I20260812 06:16:52.523859 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.013s	user 0.008s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4452,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:52.524430 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling MajorDeltaCompactionOp(daf98bb8974547c687f7606d45e5144f): perf score=1.000000
I20260812 06:16:52.707295 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: MajorDeltaCompactionOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.183s	user 0.123s	sys 0.048s 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":249,"lbm_read_time_us":11160,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33948,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:16:52.707967 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f): perf score=14.095187
I20260812 06:16:52.757081 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.049s	user 0.024s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22958,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:16:52.757642 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f): perf score=2.188937
I20260812 06:16:52.774078 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.016s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6097,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:52.774935 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling MajorDeltaCompactionOp(daf98bb8974547c687f7606d45e5144f): perf score=1.000000
I20260812 06:16:52.929733 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: MajorDeltaCompactionOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.155s	user 0.105s	sys 0.039s 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":1194,"lbm_read_time_us":9596,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29480,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:16:52.930344 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f): perf score=14.095187
I20260812 06:16:52.988829 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.058s	user 0.042s	sys 0.008s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":22988,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:52.989320 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f): perf score=2.188937
I20260812 06:16:53.001868 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4250,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:53.002528 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling MajorDeltaCompactionOp(daf98bb8974547c687f7606d45e5144f): perf score=1.000000
I20260812 06:16:53.153370 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: MajorDeltaCompactionOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.151s	user 0.125s	sys 0.019s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":163,"lbm_read_time_us":9959,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28691,"lbm_writes_lt_1ms":543,"mutex_wait_us":44,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:16:53.153992 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f): perf score=14.095187
I20260812 06:16:53.202996 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.049s	user 0.015s	sys 0.027s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20045,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:53.203583 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f): perf score=2.188937
I20260812 06:16:53.215378 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4333,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:53.216105 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling MajorDeltaCompactionOp(daf98bb8974547c687f7606d45e5144f): perf score=1.000000
I20260812 06:16:53.383211 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: MajorDeltaCompactionOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.167s	user 0.122s	sys 0.036s 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":1978,"lbm_read_time_us":9912,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31397,"lbm_writes_lt_1ms":543,"mutex_wait_us":548,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2500}
I20260812 06:16:53.383975 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f): perf score=14.095187
I20260812 06:16:53.448408 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.064s	user 0.032s	sys 0.019s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23453,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:16:53.449010 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f): perf score=2.188937
I20260812 06:16:53.462371 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.013s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4568,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:53.463254 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling MajorDeltaCompactionOp(daf98bb8974547c687f7606d45e5144f): perf score=1.000000
I20260812 06:16:53.637584 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: MajorDeltaCompactionOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.174s	user 0.125s	sys 0.043s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":791,"lbm_read_time_us":11108,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33090,"lbm_writes_lt_1ms":543,"mutex_wait_us":28,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5888,"update_count":2500}
I20260812 06:16:53.638334 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f): perf score=14.095187
I20260812 06:16:53.690174 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.052s	user 0.036s	sys 0.013s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22593,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:53.690774 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f): perf score=2.188937
I20260812 06:16:53.702271 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4374,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:53.703037 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling FlushMRSOp(daf98bb8974547c687f7606d45e5144f): perf score=1.000000
I20260812 06:16:53.734156 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: FlushMRSOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.031s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":80,"dirs.run_cpu_time_us":256,"dirs.run_wall_time_us":1344,"drs_written":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1942,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:16:53.734913 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling LogGCOp(daf98bb8974547c687f7606d45e5144f): free 132571569 bytes of WAL
I20260812 06:16:53.735179 10551 log_reader.cc:385] T daf98bb8974547c687f7606d45e5144f: removed 13 log segments from log reader
I20260812 06:16:53.735289 10551 log.cc:1079] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/daf98bb8974547c687f7606d45e5144f/wal-000000026 (ops 125-129)
I20260812 06:16:53.735339 10551 log.cc:1079] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/daf98bb8974547c687f7606d45e5144f/wal-000000027 (ops 130-134)
I20260812 06:16:53.735383 10551 log.cc:1079] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/daf98bb8974547c687f7606d45e5144f/wal-000000028 (ops 135-139)
I20260812 06:16:53.735414 10551 log.cc:1079] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/daf98bb8974547c687f7606d45e5144f/wal-000000029 (ops 140-144)
I20260812 06:16:53.735455 10551 log.cc:1079] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/daf98bb8974547c687f7606d45e5144f/wal-000000030 (ops 145-148)
I20260812 06:16:53.735513 10551 log.cc:1079] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/daf98bb8974547c687f7606d45e5144f/wal-000000031 (ops 149-153)
I20260812 06:16:53.735553 10551 log.cc:1079] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/daf98bb8974547c687f7606d45e5144f/wal-000000032 (ops 154-158)
I20260812 06:16:53.735582 10551 log.cc:1079] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/daf98bb8974547c687f7606d45e5144f/wal-000000033 (ops 159-163)
I20260812 06:16:53.735618 10551 log.cc:1079] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/daf98bb8974547c687f7606d45e5144f/wal-000000034 (ops 164-168)
I20260812 06:16:53.735658 10551 log.cc:1079] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/daf98bb8974547c687f7606d45e5144f/wal-000000035 (ops 169-173)
I20260812 06:16:53.735698 10551 log.cc:1079] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/daf98bb8974547c687f7606d45e5144f/wal-000000036 (ops 174-178)
I20260812 06:16:53.735740 10551 log.cc:1079] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/daf98bb8974547c687f7606d45e5144f/wal-000000037 (ops 179-182)
I20260812 06:16:53.735783 10551 log.cc:1079] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/daf98bb8974547c687f7606d45e5144f/wal-000000038 (ops 183-187)
I20260812 06:16:53.763552 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: LogGCOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.028s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:16:53.764499 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling UndoDeltaBlockGCOp(daf98bb8974547c687f7606d45e5144f): 491 bytes on disk
I20260812 06:16:53.765013 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: UndoDeltaBlockGCOp(daf98bb8974547c687f7606d45e5144f) 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:53.765610 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f): perf score=4.173312
I20260812 06:16:53.780453 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.015s	user 0.003s	sys 0.011s Metrics: {"bytes_written":5784656,"delete_count":0,"lbm_write_time_us":6123,"lbm_writes_lt_1ms":144,"reinsert_count":0,"update_count":705}
I20260812 06:16:53.780961 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f): perf score=1.196750
I20260812 06:16:53.790740 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.010s	user 0.007s	sys 0.001s Metrics: {"bytes_written":2420629,"delete_count":0,"lbm_write_time_us":3186,"lbm_writes_lt_1ms":62,"reinsert_count":0,"update_count":295}
I20260812 06:16:53.791380 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling MajorDeltaCompactionOp(daf98bb8974547c687f7606d45e5144f): perf score=1.000000
I20260812 06:16:54.016396 10382 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.794s	user 1.847s	sys 0.082s
I20260812 06:16:54.018895 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: MajorDeltaCompactionOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.227s	user 0.157s	sys 0.062s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979710,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":985,"lbm_read_time_us":16748,"lbm_reads_lt_1ms":774,"lbm_write_time_us":38993,"lbm_writes_lt_1ms":743,"mutex_wait_us":271,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":12288,"thread_start_us":79,"threads_started":1,"update_count":3500}
I20260812 06:16:54.019496 10646 maintenance_manager.cc:419] P 953ddfd39e104b22905c34ab335efee8: Scheduling FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f): perf score=18.063937
I20260812 06:16:54.089038 10382 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.072s	user 0.002s	sys 0.000s
I20260812 06:16:54.089711 10382 tablet_server.cc:179] TabletServer@127.10.35.129:0 shutting down...
I20260812 06:16:54.110910 10551 maintenance_manager.cc:643] P 953ddfd39e104b22905c34ab335efee8: FlushDeltaMemStoresOp(daf98bb8974547c687f7606d45e5144f) complete. Timing: real 0.091s	user 0.034s	sys 0.013s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":63502,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:16:54.111663 10382 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:16:54.112115 10382 tablet_replica.cc:333] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8: stopping tablet replica
I20260812 06:16:54.112314 10382 raft_consensus.cc:2243] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:54.112500 10382 raft_consensus.cc:2272] T daf98bb8974547c687f7606d45e5144f P 953ddfd39e104b22905c34ab335efee8 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:54.117426 10382 tablet_server.cc:196] TabletServer@127.10.35.129:0 shutdown complete.
I20260812 06:16:54.122464 10382 master.cc:562] Master@127.10.35.190:38841 shutting down...
I20260812 06:16:54.127022 10382 raft_consensus.cc:2243] T 00000000000000000000000000000000 P f9ad29d5bfc74edf8d9f32ec63096c52 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:54.127347 10382 raft_consensus.cc:2272] T 00000000000000000000000000000000 P f9ad29d5bfc74edf8d9f32ec63096c52 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:54.127470 10382 tablet_replica.cc:333] T 00000000000000000000000000000000 P f9ad29d5bfc74edf8d9f32ec63096c52: stopping tablet replica
I20260812 06:16:54.140501 10382 master.cc:584] Master@127.10.35.190:38841 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5283 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:16:54.229699 10382 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.10.35.190:41565
I20260812 06:16:54.230131 10382 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:54.232426 10702 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:54.232506 10696 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:16:54.232625 10382 server_base.cc:1061] running on GCE node
W20260812 06:16:54.232530 10698 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:54.232889 10382 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:54.232975 10382 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:54.233012 10382 hybrid_clock.cc:648] HybridClock initialized: now 1786515414233011 us; error 0 us; skew 500 ppm
I20260812 06:16:54.234157 10382 webserver.cc:533] Webserver started at http://127.10.35.190:34763/ using document root <none> and password file <none>
I20260812 06:16:54.234350 10382 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:54.234423 10382 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:54.234524 10382 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:54.234962 10382 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515408936392-10382-0/minicluster-data/master-0-root/instance:
uuid: "65a427ba8c004fe2a0bdc7f17bc39170"
format_stamp: "Formatted at 2026-08-12 06:16:54 on dist-test-slave-92m1"
I20260812 06:16:54.236765 10382 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:54.237885 10710 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:54.238195 10382 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:54.238317 10382 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515408936392-10382-0/minicluster-data/master-0-root
uuid: "65a427ba8c004fe2a0bdc7f17bc39170"
format_stamp: "Formatted at 2026-08-12 06:16:54 on dist-test-slave-92m1"
I20260812 06:16:54.238421 10382 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515408936392-10382-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515408936392-10382-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515408936392-10382-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:54.255594 10382 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:54.256140 10382 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:54.261263 10382 rpc_server.cc:307] RPC server started. Bound to: 127.10.35.190:41565
I20260812 06:16:54.263084 10790 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.10.35.190:41565 every 8 connection(s)
I20260812 06:16:54.263833 10792 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:54.282284 10792 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 65a427ba8c004fe2a0bdc7f17bc39170: Bootstrap starting.
I20260812 06:16:54.283288 10792 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 65a427ba8c004fe2a0bdc7f17bc39170: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:54.284540 10792 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 65a427ba8c004fe2a0bdc7f17bc39170: No bootstrap required, opened a new log
I20260812 06:16:54.285249 10792 raft_consensus.cc:359] T 00000000000000000000000000000000 P 65a427ba8c004fe2a0bdc7f17bc39170 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "65a427ba8c004fe2a0bdc7f17bc39170" member_type: VOTER }
I20260812 06:16:54.285351 10792 raft_consensus.cc:385] T 00000000000000000000000000000000 P 65a427ba8c004fe2a0bdc7f17bc39170 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:54.285379 10792 raft_consensus.cc:740] T 00000000000000000000000000000000 P 65a427ba8c004fe2a0bdc7f17bc39170 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 65a427ba8c004fe2a0bdc7f17bc39170, State: Initialized, Role: FOLLOWER
I20260812 06:16:54.285548 10792 consensus_queue.cc:260] T 00000000000000000000000000000000 P 65a427ba8c004fe2a0bdc7f17bc39170 [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: "65a427ba8c004fe2a0bdc7f17bc39170" member_type: VOTER }
I20260812 06:16:54.285641 10792 raft_consensus.cc:399] T 00000000000000000000000000000000 P 65a427ba8c004fe2a0bdc7f17bc39170 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:54.285668 10792 raft_consensus.cc:493] T 00000000000000000000000000000000 P 65a427ba8c004fe2a0bdc7f17bc39170 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:54.285699 10792 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 65a427ba8c004fe2a0bdc7f17bc39170 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:54.286440 10792 raft_consensus.cc:515] T 00000000000000000000000000000000 P 65a427ba8c004fe2a0bdc7f17bc39170 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "65a427ba8c004fe2a0bdc7f17bc39170" member_type: VOTER }
I20260812 06:16:54.286554 10792 leader_election.cc:304] T 00000000000000000000000000000000 P 65a427ba8c004fe2a0bdc7f17bc39170 [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: 65a427ba8c004fe2a0bdc7f17bc39170; no voters: 
I20260812 06:16:54.286731 10792 leader_election.cc:290] T 00000000000000000000000000000000 P 65a427ba8c004fe2a0bdc7f17bc39170 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:54.286976 10796 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 65a427ba8c004fe2a0bdc7f17bc39170 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:54.287252 10796 raft_consensus.cc:697] T 00000000000000000000000000000000 P 65a427ba8c004fe2a0bdc7f17bc39170 [term 1 LEADER]: Becoming Leader. State: Replica: 65a427ba8c004fe2a0bdc7f17bc39170, State: Running, Role: LEADER
I20260812 06:16:54.287317 10792 sys_catalog.cc:565] T 00000000000000000000000000000000 P 65a427ba8c004fe2a0bdc7f17bc39170 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:54.287416 10796 consensus_queue.cc:237] T 00000000000000000000000000000000 P 65a427ba8c004fe2a0bdc7f17bc39170 [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: "65a427ba8c004fe2a0bdc7f17bc39170" member_type: VOTER }
I20260812 06:16:54.287905 10798 sys_catalog.cc:455] T 00000000000000000000000000000000 P 65a427ba8c004fe2a0bdc7f17bc39170 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "65a427ba8c004fe2a0bdc7f17bc39170" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "65a427ba8c004fe2a0bdc7f17bc39170" member_type: VOTER } }
I20260812 06:16:54.288003 10798 sys_catalog.cc:458] T 00000000000000000000000000000000 P 65a427ba8c004fe2a0bdc7f17bc39170 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:54.287976 10799 sys_catalog.cc:455] T 00000000000000000000000000000000 P 65a427ba8c004fe2a0bdc7f17bc39170 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 65a427ba8c004fe2a0bdc7f17bc39170. Latest consensus state: current_term: 1 leader_uuid: "65a427ba8c004fe2a0bdc7f17bc39170" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "65a427ba8c004fe2a0bdc7f17bc39170" member_type: VOTER } }
I20260812 06:16:54.288069 10799 sys_catalog.cc:458] T 00000000000000000000000000000000 P 65a427ba8c004fe2a0bdc7f17bc39170 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:54.288604 10804 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:54.289306 10804 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:54.289593 10382 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:16:54.291339 10804 catalog_manager.cc:1383] Generated new cluster ID: 781cf15b84f742b588aff8d188094cd0
I20260812 06:16:54.291388 10804 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:54.301249 10804 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:54.301787 10804 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:54.312697 10804 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 65a427ba8c004fe2a0bdc7f17bc39170: Generated new TSK 0
I20260812 06:16:54.312937 10804 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:54.322181 10382 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:54.324415 10826 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:54.324410 10823 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:16:54.324760 10382 server_base.cc:1061] running on GCE node
W20260812 06:16:54.324487 10824 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:54.325227 10382 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:54.325276 10382 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:54.325292 10382 hybrid_clock.cc:648] HybridClock initialized: now 1786515414325293 us; error 0 us; skew 500 ppm
I20260812 06:16:54.326140 10382 webserver.cc:533] Webserver started at http://127.10.35.129:38755/ using document root <none> and password file <none>
I20260812 06:16:54.326325 10382 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:54.326387 10382 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:54.326462 10382 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:54.326857 10382 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515408936392-10382-0/minicluster-data/ts-0-root/instance:
uuid: "013f6e9cd5c24f55984f0ea83668a6db"
format_stamp: "Formatted at 2026-08-12 06:16:54 on dist-test-slave-92m1"
I20260812 06:16:54.328568 10382 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:16:54.329670 10837 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:54.330072 10382 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:16:54.330149 10382 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515408936392-10382-0/minicluster-data/ts-0-root
uuid: "013f6e9cd5c24f55984f0ea83668a6db"
format_stamp: "Formatted at 2026-08-12 06:16:54 on dist-test-slave-92m1"
I20260812 06:16:54.330253 10382 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515408936392-10382-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515408936392-10382-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515408936392-10382-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:54.346431 10382 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:54.346915 10382 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:54.347383 10382 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:54.347986 10382 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:54.348028 10382 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:54.348089 10382 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:54.348126 10382 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:54.353518 10382 rpc_server.cc:307] RPC server started. Bound to: 127.10.35.129:46343
I20260812 06:16:54.353546 10935 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.10.35.129:46343 every 8 connection(s)
I20260812 06:16:54.363785 10937 heartbeater.cc:344] Connected to a master server at 127.10.35.190:41565
I20260812 06:16:54.363934 10937 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:54.364313 10937 heartbeater.cc:507] Master 127.10.35.190:41565 requested a full tablet report, sending...
I20260812 06:16:54.365095 10738 ts_manager.cc:194] Registered new tserver with Master: 013f6e9cd5c24f55984f0ea83668a6db (127.10.35.129:46343)
I20260812 06:16:54.365422 10382 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011405288s
I20260812 06:16:54.365939 10738 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:37562
I20260812 06:16:54.374522 10738 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:37568:
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:54.386148 10881 tablet_service.cc:1511] Processing CreateTablet for tablet 25052de3b7ad4c31acdef3fe1a922015 (DEFAULT_TABLE table=heavy-update-compaction-test [id=c592ead06aba40f1be6a1528f95523c6]), partition=
I20260812 06:16:54.386533 10881 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 25052de3b7ad4c31acdef3fe1a922015. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:54.389184 10959 tablet_bootstrap.cc:492] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db: Bootstrap starting.
I20260812 06:16:54.390364 10959 tablet_bootstrap.cc:654] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:54.391707 10959 tablet_bootstrap.cc:492] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db: No bootstrap required, opened a new log
I20260812 06:16:54.391813 10959 ts_tablet_manager.cc:1403] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:16:54.392428 10959 raft_consensus.cc:359] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "013f6e9cd5c24f55984f0ea83668a6db" member_type: VOTER last_known_addr { host: "127.10.35.129" port: 46343 } }
I20260812 06:16:54.392529 10959 raft_consensus.cc:385] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:54.392551 10959 raft_consensus.cc:740] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 013f6e9cd5c24f55984f0ea83668a6db, State: Initialized, Role: FOLLOWER
I20260812 06:16:54.392730 10959 consensus_queue.cc:260] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db [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: "013f6e9cd5c24f55984f0ea83668a6db" member_type: VOTER last_known_addr { host: "127.10.35.129" port: 46343 } }
I20260812 06:16:54.392820 10959 raft_consensus.cc:399] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:54.392889 10959 raft_consensus.cc:493] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:54.392944 10959 raft_consensus.cc:3060] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:54.432704 10959 raft_consensus.cc:515] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "013f6e9cd5c24f55984f0ea83668a6db" member_type: VOTER last_known_addr { host: "127.10.35.129" port: 46343 } }
I20260812 06:16:54.433060 10959 leader_election.cc:304] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db [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: 013f6e9cd5c24f55984f0ea83668a6db; no voters: 
I20260812 06:16:54.433390 10959 leader_election.cc:290] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:54.433614 10963 raft_consensus.cc:2804] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:54.433888 10963 raft_consensus.cc:697] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db [term 1 LEADER]: Becoming Leader. State: Replica: 013f6e9cd5c24f55984f0ea83668a6db, State: Running, Role: LEADER
I20260812 06:16:54.433928 10959 ts_tablet_manager.cc:1434] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db: Time spent starting tablet: real 0.042s	user 0.003s	sys 0.000s
I20260812 06:16:54.434065 10937 heartbeater.cc:499] Master 127.10.35.190:41565 was elected leader, sending a full tablet report...
I20260812 06:16:54.434127 10963 consensus_queue.cc:237] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db [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: "013f6e9cd5c24f55984f0ea83668a6db" member_type: VOTER last_known_addr { host: "127.10.35.129" port: 46343 } }
I20260812 06:16:54.435705 10738 catalog_manager.cc:5719] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db reported cstate change: term changed from 0 to 1, leader changed from <none> to 013f6e9cd5c24f55984f0ea83668a6db (127.10.35.129). New cstate: current_term: 1 leader_uuid: "013f6e9cd5c24f55984f0ea83668a6db" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "013f6e9cd5c24f55984f0ea83668a6db" member_type: VOTER last_known_addr { host: "127.10.35.129" port: 46343 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:54.506412 10382 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.058s	user 0.017s	sys 0.008s
I20260812 06:16:54.604485 10939 maintenance_manager.cc:419] P 013f6e9cd5c24f55984f0ea83668a6db: Scheduling FlushMRSOp(25052de3b7ad4c31acdef3fe1a922015): perf score=10.125253
I20260812 06:16:54.746882 10845 maintenance_manager.cc:643] P 013f6e9cd5c24f55984f0ea83668a6db: FlushMRSOp(25052de3b7ad4c31acdef3fe1a922015) complete. Timing: real 0.142s	user 0.080s	sys 0.044s Metrics: {"bytes_written":8902492,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":54,"dirs.run_cpu_time_us":222,"dirs.run_wall_time_us":56189,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":29224,"lbm_writes_lt_1ms":474,"mutex_wait_us":873,"peak_mem_usage":0,"reinsert_count":0,"rows_written":102,"spinlock_wait_cycles":12032,"update_count":1085}
I20260812 06:16:54.747784 10939 maintenance_manager.cc:419] P 013f6e9cd5c24f55984f0ea83668a6db: Scheduling LogGCOp(25052de3b7ad4c31acdef3fe1a922015): free 11976772 bytes of WAL
I20260812 06:16:54.748121 10845 log_reader.cc:385] T 25052de3b7ad4c31acdef3fe1a922015: removed 1 log segments from log reader
I20260812 06:16:54.748211 10845 log.cc:1079] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/25052de3b7ad4c31acdef3fe1a922015/wal-000000001 (ops 1-6)
I20260812 06:16:54.750815 10845 maintenance_manager.cc:643] P 013f6e9cd5c24f55984f0ea83668a6db: LogGCOp(25052de3b7ad4c31acdef3fe1a922015) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:16:54.751183 10939 maintenance_manager.cc:419] P 013f6e9cd5c24f55984f0ea83668a6db: Scheduling FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015): perf score=2.188937
I20260812 06:16:54.844141 10845 maintenance_manager.cc:643] P 013f6e9cd5c24f55984f0ea83668a6db: FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015) complete. Timing: real 0.093s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3815484,"delete_count":0,"lbm_write_time_us":4061,"lbm_writes_lt_1ms":96,"reinsert_count":0,"update_count":465}
I20260812 06:16:54.845018 10939 maintenance_manager.cc:419] P 013f6e9cd5c24f55984f0ea83668a6db: Scheduling UndoDeltaBlockGCOp(25052de3b7ad4c31acdef3fe1a922015): 8206537 bytes on disk
I20260812 06:16:54.845636 10845 maintenance_manager.cc:643] P 013f6e9cd5c24f55984f0ea83668a6db: UndoDeltaBlockGCOp(25052de3b7ad4c31acdef3fe1a922015) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":107,"lbm_reads_lt_1ms":4}
I20260812 06:16:54.846256 10939 maintenance_manager.cc:419] P 013f6e9cd5c24f55984f0ea83668a6db: Scheduling FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015): perf score=6.157687
I20260812 06:16:54.941892 10845 maintenance_manager.cc:643] P 013f6e9cd5c24f55984f0ea83668a6db: FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015) complete. Timing: real 0.095s	user 0.019s	sys 0.003s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":9678,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:16:54.942452 10939 maintenance_manager.cc:419] P 013f6e9cd5c24f55984f0ea83668a6db: Scheduling FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015): perf score=7.149875
I20260812 06:16:55.048516 10845 maintenance_manager.cc:643] P 013f6e9cd5c24f55984f0ea83668a6db: FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015) complete. Timing: real 0.106s	user 0.005s	sys 0.015s Metrics: {"bytes_written":8615325,"delete_count":0,"lbm_write_time_us":8661,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:16:55.049217 10939 maintenance_manager.cc:419] P 013f6e9cd5c24f55984f0ea83668a6db: Scheduling FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015): perf score=10.126437
I20260812 06:16:55.159897 10845 maintenance_manager.cc:643] P 013f6e9cd5c24f55984f0ea83668a6db: FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015) complete. Timing: real 0.110s	user 0.028s	sys 0.012s Metrics: {"bytes_written":11897250,"delete_count":0,"lbm_write_time_us":14596,"lbm_writes_lt_1ms":293,"reinsert_count":0,"update_count":1450}
I20260812 06:16:55.160470 10939 maintenance_manager.cc:419] P 013f6e9cd5c24f55984f0ea83668a6db: Scheduling FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015): perf score=6.157687
I20260812 06:16:55.259509 10845 maintenance_manager.cc:643] P 013f6e9cd5c24f55984f0ea83668a6db: FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015) complete. Timing: real 0.099s	user 0.017s	sys 0.008s Metrics: {"bytes_written":8205077,"delete_count":0,"lbm_write_time_us":10208,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:55.260320 10939 maintenance_manager.cc:419] P 013f6e9cd5c24f55984f0ea83668a6db: Scheduling FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015): perf score=6.157687
I20260812 06:16:55.287314 10845 maintenance_manager.cc:643] P 013f6e9cd5c24f55984f0ea83668a6db: FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015) complete. Timing: real 0.026s	user 0.010s	sys 0.016s Metrics: {"bytes_written":8369175,"delete_count":0,"lbm_write_time_us":10965,"lbm_writes_lt_1ms":207,"reinsert_count":0,"update_count":1020}
I20260812 06:16:55.287834 10939 maintenance_manager.cc:419] P 013f6e9cd5c24f55984f0ea83668a6db: Scheduling FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015): perf score=2.188937
I20260812 06:16:55.381819 10845 maintenance_manager.cc:643] P 013f6e9cd5c24f55984f0ea83668a6db: FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015) complete. Timing: real 0.094s	user 0.006s	sys 0.009s Metrics: {"bytes_written":3938559,"delete_count":0,"lbm_write_time_us":5821,"lbm_writes_lt_1ms":99,"reinsert_count":0,"update_count":480}
I20260812 06:16:55.382395 10939 maintenance_manager.cc:419] P 013f6e9cd5c24f55984f0ea83668a6db: Scheduling FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015): perf score=6.157687
I20260812 06:16:55.480185 10845 maintenance_manager.cc:643] P 013f6e9cd5c24f55984f0ea83668a6db: FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015) complete. Timing: real 0.098s	user 0.013s	sys 0.016s Metrics: {"bytes_written":8205079,"delete_count":0,"lbm_write_time_us":12493,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:55.480850 10939 maintenance_manager.cc:419] P 013f6e9cd5c24f55984f0ea83668a6db: Scheduling FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015): perf score=6.157687
I20260812 06:16:55.577167 10845 maintenance_manager.cc:643] P 013f6e9cd5c24f55984f0ea83668a6db: FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015) complete. Timing: real 0.096s	user 0.012s	sys 0.017s Metrics: {"bytes_written":8205077,"delete_count":0,"lbm_write_time_us":13030,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:55.577838 10939 maintenance_manager.cc:419] P 013f6e9cd5c24f55984f0ea83668a6db: Scheduling FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015): perf score=6.157687
I20260812 06:16:55.679347 10845 maintenance_manager.cc:643] P 013f6e9cd5c24f55984f0ea83668a6db: FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015) complete. Timing: real 0.101s	user 0.011s	sys 0.021s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":13528,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:55.680011 10939 maintenance_manager.cc:419] P 013f6e9cd5c24f55984f0ea83668a6db: Scheduling FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015): perf score=6.157687
I20260812 06:16:55.779750 10845 maintenance_manager.cc:643] P 013f6e9cd5c24f55984f0ea83668a6db: FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015) complete. Timing: real 0.100s	user 0.016s	sys 0.013s Metrics: {"bytes_written":8205077,"delete_count":0,"lbm_write_time_us":12126,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:55.780320 10939 maintenance_manager.cc:419] P 013f6e9cd5c24f55984f0ea83668a6db: Scheduling FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015): perf score=6.157687
I20260812 06:16:55.882817 10845 maintenance_manager.cc:643] P 013f6e9cd5c24f55984f0ea83668a6db: FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015) complete. Timing: real 0.102s	user 0.021s	sys 0.000s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":8868,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:55.883723 10939 maintenance_manager.cc:419] P 013f6e9cd5c24f55984f0ea83668a6db: Scheduling FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015): perf score=6.157687
I20260812 06:16:55.983879 10845 maintenance_manager.cc:643] P 013f6e9cd5c24f55984f0ea83668a6db: FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015) complete. Timing: real 0.100s	user 0.017s	sys 0.009s Metrics: {"bytes_written":8205077,"delete_count":0,"lbm_write_time_us":10454,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:55.984747 10939 maintenance_manager.cc:419] P 013f6e9cd5c24f55984f0ea83668a6db: Scheduling FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015): perf score=7.149875
I20260812 06:16:56.079722 10845 maintenance_manager.cc:643] P 013f6e9cd5c24f55984f0ea83668a6db: FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015) complete. Timing: real 0.095s	user 0.012s	sys 0.017s Metrics: {"bytes_written":8615325,"delete_count":0,"lbm_write_time_us":11913,"lbm_writes_lt_1ms":213,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":1050}
I20260812 06:16:56.080255 10939 maintenance_manager.cc:419] P 013f6e9cd5c24f55984f0ea83668a6db: Scheduling FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015): perf score=6.157687
I20260812 06:16:56.219579 10845 maintenance_manager.cc:643] P 013f6e9cd5c24f55984f0ea83668a6db: FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015) complete. Timing: real 0.139s	user 0.011s	sys 0.008s Metrics: {"bytes_written":8205079,"delete_count":0,"lbm_write_time_us":8067,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:56.220270 10939 maintenance_manager.cc:419] P 013f6e9cd5c24f55984f0ea83668a6db: Scheduling FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015): perf score=11.118625
I20260812 06:16:56.319941 10845 maintenance_manager.cc:643] P 013f6e9cd5c24f55984f0ea83668a6db: FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015) complete. Timing: real 0.099s	user 0.028s	sys 0.008s Metrics: {"bytes_written":12922856,"delete_count":0,"lbm_write_time_us":15359,"lbm_writes_lt_1ms":318,"reinsert_count":0,"update_count":1575}
I20260812 06:16:56.320734 10939 maintenance_manager.cc:419] P 013f6e9cd5c24f55984f0ea83668a6db: Scheduling FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015): perf score=7.149875
I20260812 06:16:56.425993 10845 maintenance_manager.cc:643] P 013f6e9cd5c24f55984f0ea83668a6db: FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015) complete. Timing: real 0.105s	user 0.009s	sys 0.012s Metrics: {"bytes_written":8943518,"delete_count":0,"lbm_write_time_us":10024,"lbm_writes_lt_1ms":221,"reinsert_count":0,"update_count":1090}
I20260812 06:16:56.426867 10939 maintenance_manager.cc:419] P 013f6e9cd5c24f55984f0ea83668a6db: Scheduling FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015): perf score=9.134250
I20260812 06:16:56.526949 10845 maintenance_manager.cc:643] P 013f6e9cd5c24f55984f0ea83668a6db: FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015) complete. Timing: real 0.100s	user 0.019s	sys 0.015s Metrics: {"bytes_written":10543460,"delete_count":0,"lbm_write_time_us":15372,"lbm_writes_lt_1ms":260,"reinsert_count":0,"update_count":1285}
I20260812 06:16:56.527865 10939 maintenance_manager.cc:419] P 013f6e9cd5c24f55984f0ea83668a6db: Scheduling FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015): perf score=6.157687
I20260812 06:16:56.633039 10845 maintenance_manager.cc:643] P 013f6e9cd5c24f55984f0ea83668a6db: FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015) complete. Timing: real 0.105s	user 0.010s	sys 0.013s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":8733,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:56.633705 10939 maintenance_manager.cc:419] P 013f6e9cd5c24f55984f0ea83668a6db: Scheduling FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015): perf score=8.142062
I20260812 06:16:56.734259 10845 maintenance_manager.cc:643] P 013f6e9cd5c24f55984f0ea83668a6db: FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015) complete. Timing: real 0.100s	user 0.013s	sys 0.008s Metrics: {"bytes_written":9558873,"delete_count":0,"lbm_write_time_us":9812,"lbm_writes_lt_1ms":236,"reinsert_count":0,"update_count":1165}
I20260812 06:16:56.734915 10939 maintenance_manager.cc:419] P 013f6e9cd5c24f55984f0ea83668a6db: Scheduling FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015): perf score=9.134250
I20260812 06:16:56.833178 10845 maintenance_manager.cc:643] P 013f6e9cd5c24f55984f0ea83668a6db: FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015) complete. Timing: real 0.098s	user 0.012s	sys 0.015s Metrics: {"bytes_written":10584487,"delete_count":0,"lbm_write_time_us":12216,"lbm_writes_lt_1ms":261,"reinsert_count":0,"update_count":1290}
I20260812 06:16:56.833845 10939 maintenance_manager.cc:419] P 013f6e9cd5c24f55984f0ea83668a6db: Scheduling FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015): perf score=7.149875
I20260812 06:16:56.873124 10845 maintenance_manager.cc:643] P 013f6e9cd5c24f55984f0ea83668a6db: FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015) complete. Timing: real 0.039s	user 0.019s	sys 0.008s Metrics: {"bytes_written":8574302,"delete_count":0,"lbm_write_time_us":11969,"lbm_writes_lt_1ms":212,"reinsert_count":0,"update_count":1045}
I20260812 06:16:56.873687 10939 maintenance_manager.cc:419] P 013f6e9cd5c24f55984f0ea83668a6db: Scheduling FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015): perf score=2.188937
I20260812 06:16:56.884516 10845 maintenance_manager.cc:643] P 013f6e9cd5c24f55984f0ea83668a6db: FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015) complete. Timing: real 0.011s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3913,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:56.885563 10939 maintenance_manager.cc:419] P 013f6e9cd5c24f55984f0ea83668a6db: Scheduling FlushMRSOp(25052de3b7ad4c31acdef3fe1a922015): perf score=1.000000
I20260812 06:16:56.918588 10845 maintenance_manager.cc:643] P 013f6e9cd5c24f55984f0ea83668a6db: FlushMRSOp(25052de3b7ad4c31acdef3fe1a922015) complete. Timing: real 0.033s	user 0.031s	sys 0.000s Metrics: {"bytes_written":2013187,"cfile_init":1,"dirs.queue_time_us":234,"dirs.run_cpu_time_us":222,"dirs.run_wall_time_us":1358,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2335,"lbm_writes_lt_1ms":44,"peak_mem_usage":0,"rows_written":49,"spinlock_wait_cycles":14208,"thread_start_us":104,"threads_started":1}
I20260812 06:16:56.919335 10939 maintenance_manager.cc:419] P 013f6e9cd5c24f55984f0ea83668a6db: Scheduling LogGCOp(25052de3b7ad4c31acdef3fe1a922015): free 204146615 bytes of WAL
I20260812 06:16:56.919595 10845 log_reader.cc:385] T 25052de3b7ad4c31acdef3fe1a922015: removed 20 log segments from log reader
I20260812 06:16:56.919638 10845 log.cc:1079] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/25052de3b7ad4c31acdef3fe1a922015/wal-000000002 (ops 7-11)
I20260812 06:16:56.919667 10845 log.cc:1079] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/25052de3b7ad4c31acdef3fe1a922015/wal-000000003 (ops 12-16)
I20260812 06:16:56.919731 10845 log.cc:1079] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/25052de3b7ad4c31acdef3fe1a922015/wal-000000004 (ops 17-21)
I20260812 06:16:56.919795 10845 log.cc:1079] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/25052de3b7ad4c31acdef3fe1a922015/wal-000000005 (ops 22-26)
I20260812 06:16:56.919837 10845 log.cc:1079] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/25052de3b7ad4c31acdef3fe1a922015/wal-000000006 (ops 27-31)
I20260812 06:16:56.919875 10845 log.cc:1079] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/25052de3b7ad4c31acdef3fe1a922015/wal-000000007 (ops 32-36)
I20260812 06:16:56.919920 10845 log.cc:1079] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/25052de3b7ad4c31acdef3fe1a922015/wal-000000008 (ops 37-41)
I20260812 06:16:56.919962 10845 log.cc:1079] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/25052de3b7ad4c31acdef3fe1a922015/wal-000000009 (ops 42-46)
I20260812 06:16:56.920001 10845 log.cc:1079] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/25052de3b7ad4c31acdef3fe1a922015/wal-000000010 (ops 47-51)
I20260812 06:16:56.920042 10845 log.cc:1079] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/25052de3b7ad4c31acdef3fe1a922015/wal-000000011 (ops 52-56)
I20260812 06:16:56.920079 10845 log.cc:1079] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/25052de3b7ad4c31acdef3fe1a922015/wal-000000012 (ops 57-61)
I20260812 06:16:56.920117 10845 log.cc:1079] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/25052de3b7ad4c31acdef3fe1a922015/wal-000000013 (ops 62-66)
I20260812 06:16:56.920152 10845 log.cc:1079] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/25052de3b7ad4c31acdef3fe1a922015/wal-000000014 (ops 67-71)
I20260812 06:16:56.920189 10845 log.cc:1079] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/25052de3b7ad4c31acdef3fe1a922015/wal-000000015 (ops 72-76)
I20260812 06:16:56.920228 10845 log.cc:1079] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/25052de3b7ad4c31acdef3fe1a922015/wal-000000016 (ops 77-81)
I20260812 06:16:56.920267 10845 log.cc:1079] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/25052de3b7ad4c31acdef3fe1a922015/wal-000000017 (ops 82-86)
I20260812 06:16:56.920305 10845 log.cc:1079] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/25052de3b7ad4c31acdef3fe1a922015/wal-000000018 (ops 87-91)
I20260812 06:16:56.920343 10845 log.cc:1079] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/25052de3b7ad4c31acdef3fe1a922015/wal-000000019 (ops 92-96)
I20260812 06:16:56.920382 10845 log.cc:1079] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/25052de3b7ad4c31acdef3fe1a922015/wal-000000020 (ops 97-100)
I20260812 06:16:56.920423 10845 log.cc:1079] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/25052de3b7ad4c31acdef3fe1a922015/wal-000000021 (ops 101-105)
I20260812 06:16:56.965098 10845 maintenance_manager.cc:643] P 013f6e9cd5c24f55984f0ea83668a6db: LogGCOp(25052de3b7ad4c31acdef3fe1a922015) complete. Timing: real 0.046s	user 0.000s	sys 0.044s Metrics: {}
I20260812 06:16:56.965651 10939 maintenance_manager.cc:419] P 013f6e9cd5c24f55984f0ea83668a6db: Scheduling UndoDeltaBlockGCOp(25052de3b7ad4c31acdef3fe1a922015): 688 bytes on disk
I20260812 06:16:56.966207 10845 maintenance_manager.cc:643] P 013f6e9cd5c24f55984f0ea83668a6db: UndoDeltaBlockGCOp(25052de3b7ad4c31acdef3fe1a922015) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4}
I20260812 06:16:56.966795 10939 maintenance_manager.cc:419] P 013f6e9cd5c24f55984f0ea83668a6db: Scheduling FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015): perf score=6.157687
I20260812 06:16:56.996752 10845 maintenance_manager.cc:643] P 013f6e9cd5c24f55984f0ea83668a6db: FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015) complete. Timing: real 0.030s	user 0.023s	sys 0.003s Metrics: {"bytes_written":8205077,"delete_count":0,"lbm_write_time_us":11587,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:56.997287 10939 maintenance_manager.cc:419] P 013f6e9cd5c24f55984f0ea83668a6db: Scheduling MajorDeltaCompactionOp(25052de3b7ad4c31acdef3fe1a922015): perf score=1.000000
I20260812 06:16:58.571696 10845 maintenance_manager.cc:643] P 013f6e9cd5c24f55984f0ea83668a6db: MajorDeltaCompactionOp(25052de3b7ad4c31acdef3fe1a922015) complete. Timing: real 1.574s	user 0.983s	sys 0.585s Metrics: {"cfile_cache_miss":5155,"cfile_cache_miss_bytes":213406505,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":25,"delta_iterators_relevant":25,"dirs.queue_time_us":1050,"lbm_read_time_us":97680,"lbm_reads_lt_1ms":5183,"lbm_write_time_us":337504,"lbm_writes_lt_1ms":5147,"mutex_wait_us":83,"peak_mem_usage":634738212,"reinsert_count":0,"spinlock_wait_cycles":17280,"thread_start_us":484,"threads_started":7,"update_count":25500}
I20260812 06:16:58.572657 10939 maintenance_manager.cc:419] P 013f6e9cd5c24f55984f0ea83668a6db: Scheduling FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015): perf score=96.446750
I20260812 06:16:58.981918 10845 maintenance_manager.cc:643] P 013f6e9cd5c24f55984f0ea83668a6db: FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015) complete. Timing: real 0.409s	user 0.209s	sys 0.087s Metrics: {"bytes_written":101165873,"delete_count":0,"lbm_write_time_us":134535,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":2470,"reinsert_count":0,"update_count":12330}
I20260812 06:16:58.982632 10939 maintenance_manager.cc:419] P 013f6e9cd5c24f55984f0ea83668a6db: Scheduling FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015): perf score=28.978000
I20260812 06:16:59.169631 10845 maintenance_manager.cc:643] P 013f6e9cd5c24f55984f0ea83668a6db: FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015) complete. Timing: real 0.187s	user 0.054s	sys 0.024s Metrics: {"bytes_written":31137559,"delete_count":0,"lbm_write_time_us":35681,"lbm_writes_lt_1ms":762,"reinsert_count":0,"update_count":3795}
I20260812 06:16:59.170420 10939 maintenance_manager.cc:419] P 013f6e9cd5c24f55984f0ea83668a6db: Scheduling FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015): perf score=14.095187
I20260812 06:16:59.352988 10845 maintenance_manager.cc:643] P 013f6e9cd5c24f55984f0ea83668a6db: FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015) complete. Timing: real 0.182s	user 0.021s	sys 0.030s Metrics: {"bytes_written":15794550,"delete_count":0,"lbm_write_time_us":20246,"lbm_writes_lt_1ms":388,"reinsert_count":0,"update_count":1925}
I20260812 06:16:59.353601 10939 maintenance_manager.cc:419] P 013f6e9cd5c24f55984f0ea83668a6db: Scheduling FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015): perf score=15.087375
I20260812 06:16:59.416648 10845 maintenance_manager.cc:643] P 013f6e9cd5c24f55984f0ea83668a6db: FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015) complete. Timing: real 0.063s	user 0.033s	sys 0.023s Metrics: {"bytes_written":17394489,"delete_count":0,"lbm_write_time_us":26696,"lbm_writes_lt_1ms":427,"reinsert_count":0,"update_count":2120}
I20260812 06:16:59.417137 10939 maintenance_manager.cc:419] P 013f6e9cd5c24f55984f0ea83668a6db: Scheduling FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015): perf score=1.196750
I20260812 06:16:59.430042 10845 maintenance_manager.cc:643] P 013f6e9cd5c24f55984f0ea83668a6db: FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015) complete. Timing: real 0.013s	user 0.000s	sys 0.007s Metrics: {"bytes_written":3118059,"delete_count":0,"lbm_write_time_us":3138,"lbm_writes_lt_1ms":79,"reinsert_count":0,"update_count":380}
I20260812 06:16:59.430634 10939 maintenance_manager.cc:419] P 013f6e9cd5c24f55984f0ea83668a6db: Scheduling FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015): perf score=2.188937
I20260812 06:16:59.440898 10845 maintenance_manager.cc:643] P 013f6e9cd5c24f55984f0ea83668a6db: FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3665,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:59.441535 10939 maintenance_manager.cc:419] P 013f6e9cd5c24f55984f0ea83668a6db: Scheduling FlushMRSOp(25052de3b7ad4c31acdef3fe1a922015): perf score=1.000000
I20260812 06:16:59.480621 10845 maintenance_manager.cc:643] P 013f6e9cd5c24f55984f0ea83668a6db: FlushMRSOp(25052de3b7ad4c31acdef3fe1a922015) complete. Timing: real 0.039s	user 0.030s	sys 0.008s Metrics: {"bytes_written":1808281,"cfile_init":1,"dirs.queue_time_us":62,"dirs.run_cpu_time_us":240,"dirs.run_wall_time_us":1358,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2800,"lbm_writes_lt_1ms":44,"peak_mem_usage":0,"rows_written":44,"spinlock_wait_cycles":1792}
I20260812 06:16:59.481257 10939 maintenance_manager.cc:419] P 013f6e9cd5c24f55984f0ea83668a6db: Scheduling LogGCOp(25052de3b7ad4c31acdef3fe1a922015): free 174594796 bytes of WAL
I20260812 06:16:59.481485 10845 log_reader.cc:385] T 25052de3b7ad4c31acdef3fe1a922015: removed 17 log segments from log reader
I20260812 06:16:59.481552 10845 log.cc:1079] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/25052de3b7ad4c31acdef3fe1a922015/wal-000000022 (ops 106-110)
I20260812 06:16:59.481606 10845 log.cc:1079] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/25052de3b7ad4c31acdef3fe1a922015/wal-000000023 (ops 111-115)
I20260812 06:16:59.481663 10845 log.cc:1079] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/25052de3b7ad4c31acdef3fe1a922015/wal-000000024 (ops 116-120)
I20260812 06:16:59.481703 10845 log.cc:1079] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/25052de3b7ad4c31acdef3fe1a922015/wal-000000025 (ops 121-125)
I20260812 06:16:59.481739 10845 log.cc:1079] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/25052de3b7ad4c31acdef3fe1a922015/wal-000000026 (ops 126-130)
I20260812 06:16:59.481776 10845 log.cc:1079] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/25052de3b7ad4c31acdef3fe1a922015/wal-000000027 (ops 131-135)
I20260812 06:16:59.481812 10845 log.cc:1079] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/25052de3b7ad4c31acdef3fe1a922015/wal-000000028 (ops 136-140)
I20260812 06:16:59.481849 10845 log.cc:1079] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/25052de3b7ad4c31acdef3fe1a922015/wal-000000029 (ops 141-145)
I20260812 06:16:59.481886 10845 log.cc:1079] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/25052de3b7ad4c31acdef3fe1a922015/wal-000000030 (ops 146-150)
I20260812 06:16:59.481923 10845 log.cc:1079] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/25052de3b7ad4c31acdef3fe1a922015/wal-000000031 (ops 151-155)
I20260812 06:16:59.481959 10845 log.cc:1079] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/25052de3b7ad4c31acdef3fe1a922015/wal-000000032 (ops 156-160)
I20260812 06:16:59.481997 10845 log.cc:1079] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/25052de3b7ad4c31acdef3fe1a922015/wal-000000033 (ops 161-165)
I20260812 06:16:59.482031 10845 log.cc:1079] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/25052de3b7ad4c31acdef3fe1a922015/wal-000000034 (ops 166-170)
I20260812 06:16:59.482071 10845 log.cc:1079] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/25052de3b7ad4c31acdef3fe1a922015/wal-000000035 (ops 171-174)
I20260812 06:16:59.482107 10845 log.cc:1079] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/25052de3b7ad4c31acdef3fe1a922015/wal-000000036 (ops 175-179)
I20260812 06:16:59.482143 10845 log.cc:1079] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/25052de3b7ad4c31acdef3fe1a922015/wal-000000037 (ops 180-184)
I20260812 06:16:59.482179 10845 log.cc:1079] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/25052de3b7ad4c31acdef3fe1a922015/wal-000000038 (ops 185-189)
I20260812 06:16:59.517853 10845 maintenance_manager.cc:643] P 013f6e9cd5c24f55984f0ea83668a6db: LogGCOp(25052de3b7ad4c31acdef3fe1a922015) complete. Timing: real 0.036s	user 0.000s	sys 0.034s Metrics: {}
I20260812 06:16:59.518270 10939 maintenance_manager.cc:419] P 013f6e9cd5c24f55984f0ea83668a6db: Scheduling FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015): perf score=6.157687
I20260812 06:16:59.539376 10845 maintenance_manager.cc:643] P 013f6e9cd5c24f55984f0ea83668a6db: FlushDeltaMemStoresOp(25052de3b7ad4c31acdef3fe1a922015) complete. Timing: real 0.021s	user 0.014s	sys 0.007s Metrics: {"bytes_written":8082005,"delete_count":0,"lbm_write_time_us":8339,"lbm_writes_lt_1ms":200,"reinsert_count":0,"update_count":985}
I20260812 06:16:59.539947 10939 maintenance_manager.cc:419] P 013f6e9cd5c24f55984f0ea83668a6db: Scheduling LogGCOp(25052de3b7ad4c31acdef3fe1a922015): free 12017961 bytes of WAL
I20260812 06:16:59.540205 10845 log_reader.cc:385] T 25052de3b7ad4c31acdef3fe1a922015: removed 1 log segments from log reader
I20260812 06:16:59.540257 10845 log.cc:1079] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db: Deleting log segment in path: /tmp/dist-test-taskSDhPp5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515408936392-10382-0/minicluster-data/ts-0-root/wals/25052de3b7ad4c31acdef3fe1a922015/wal-000000039 (ops 190-194)
I20260812 06:16:59.544137 10845 maintenance_manager.cc:643] P 013f6e9cd5c24f55984f0ea83668a6db: LogGCOp(25052de3b7ad4c31acdef3fe1a922015) complete. Timing: real 0.004s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:16:59.544570 10939 maintenance_manager.cc:419] P 013f6e9cd5c24f55984f0ea83668a6db: Scheduling UndoDeltaBlockGCOp(25052de3b7ad4c31acdef3fe1a922015): 629 bytes on disk
I20260812 06:16:59.545059 10845 maintenance_manager.cc:643] P 013f6e9cd5c24f55984f0ea83668a6db: UndoDeltaBlockGCOp(25052de3b7ad4c31acdef3fe1a922015) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":75,"lbm_reads_lt_1ms":4}
I20260812 06:16:59.545617 10939 maintenance_manager.cc:419] P 013f6e9cd5c24f55984f0ea83668a6db: Scheduling MajorDeltaCompactionOp(25052de3b7ad4c31acdef3fe1a922015): perf score=1.000000
I20260812 06:16:59.681465 10382 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.175s	user 1.786s	sys 0.126s
I20260812 06:17:00.099452 10382 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.418s	user 0.003s	sys 0.000s
I20260812 06:17:00.100044 10382 tablet_server.cc:179] TabletServer@127.10.35.129:0 shutting down...
I20260812 06:17:00.702493 10845 maintenance_manager.cc:643] P 013f6e9cd5c24f55984f0ea83668a6db: MajorDeltaCompactionOp(25052de3b7ad4c31acdef3fe1a922015) complete. Timing: real 1.157s	user 0.644s	sys 0.512s Metrics: {"cfile_cache_miss":4436,"cfile_cache_miss_bytes":184564475,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":7,"delta_iterators_relevant":7,"dirs.queue_time_us":1200,"lbm_read_time_us":80071,"lbm_reads_lt_1ms":4468,"lbm_write_time_us":190462,"lbm_writes_lt_1ms":4443,"mutex_wait_us":35,"peak_mem_usage":546588719,"reinsert_count":0,"spinlock_wait_cycles":780032,"thread_start_us":497,"threads_started":7,"update_count":21985}
I20260812 06:17:00.703230 10382 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:00.703554 10382 tablet_replica.cc:333] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db: stopping tablet replica
I20260812 06:17:00.703709 10382 raft_consensus.cc:2243] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:00.703891 10382 raft_consensus.cc:2272] T 25052de3b7ad4c31acdef3fe1a922015 P 013f6e9cd5c24f55984f0ea83668a6db [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:00.721235 10382 tablet_server.cc:196] TabletServer@127.10.35.129:0 shutdown complete.
I20260812 06:17:01.385358 10382 master.cc:562] Master@127.10.35.190:41565 shutting down...
I20260812 06:17:01.392750 10382 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 65a427ba8c004fe2a0bdc7f17bc39170 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:01.393036 10382 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 65a427ba8c004fe2a0bdc7f17bc39170 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:01.393142 10382 tablet_replica.cc:333] T 00000000000000000000000000000000 P 65a427ba8c004fe2a0bdc7f17bc39170: stopping tablet replica
I20260812 06:17:01.652258 10382 master.cc:584] Master@127.10.35.190:41565 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (7512 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (12797 ms total)

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