[==========] 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:52.414845 21636 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.21.33.62:44943
I20260812 06:16:52.415715 21636 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:52.416260 21636 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:16:52.422127 21636 server_base.cc:1061] running on GCE node
W20260812 06:16:52.422147 21649 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:52.422487 21645 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:52.422605 21646 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:52.423010 21636 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:52.423103 21636 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:52.423143 21636 hybrid_clock.cc:648] HybridClock initialized: now 1786515412423141 us; error 0 us; skew 500 ppm
I20260812 06:16:52.424678 21636 webserver.cc:533] Webserver started at http://127.21.33.62:34865/ using document root <none> and password file <none>
I20260812 06:16:52.425130 21636 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:52.425187 21636 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:52.425390 21636 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:52.426872 21636 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412404881-21636-0/minicluster-data/master-0-root/instance:
uuid: "85d10bc4a60345928987481cec991d1a"
format_stamp: "Formatted at 2026-08-12 06:16:52 on dist-test-slave-tc2s"
I20260812 06:16:52.429970 21636 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:16:52.431733 21655 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:52.432621 21636 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:16:52.432714 21636 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412404881-21636-0/minicluster-data/master-0-root
uuid: "85d10bc4a60345928987481cec991d1a"
format_stamp: "Formatted at 2026-08-12 06:16:52 on dist-test-slave-tc2s"
I20260812 06:16:52.432789 21636 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412404881-21636-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412404881-21636-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412404881-21636-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:52.460311 21636 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:52.460831 21636 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:52.460961 21636 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:52.467640 21636 rpc_server.cc:307] RPC server started. Bound to: 127.21.33.62:44943
I20260812 06:16:52.467644 21757 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.21.33.62:44943 every 8 connection(s)
I20260812 06:16:52.469619 21759 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:52.474548 21759 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 85d10bc4a60345928987481cec991d1a: Bootstrap starting.
I20260812 06:16:52.476661 21759 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 85d10bc4a60345928987481cec991d1a: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:52.477456 21759 log.cc:826] T 00000000000000000000000000000000 P 85d10bc4a60345928987481cec991d1a: Log is configured to *not* fsync() on all Append() calls
I20260812 06:16:52.478890 21759 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 85d10bc4a60345928987481cec991d1a: No bootstrap required, opened a new log
I20260812 06:16:52.481405 21759 raft_consensus.cc:359] T 00000000000000000000000000000000 P 85d10bc4a60345928987481cec991d1a [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "85d10bc4a60345928987481cec991d1a" member_type: VOTER }
I20260812 06:16:52.481562 21759 raft_consensus.cc:385] T 00000000000000000000000000000000 P 85d10bc4a60345928987481cec991d1a [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:52.481606 21759 raft_consensus.cc:740] T 00000000000000000000000000000000 P 85d10bc4a60345928987481cec991d1a [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 85d10bc4a60345928987481cec991d1a, State: Initialized, Role: FOLLOWER
I20260812 06:16:52.482167 21759 consensus_queue.cc:260] T 00000000000000000000000000000000 P 85d10bc4a60345928987481cec991d1a [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: "85d10bc4a60345928987481cec991d1a" member_type: VOTER }
I20260812 06:16:52.482306 21759 raft_consensus.cc:399] T 00000000000000000000000000000000 P 85d10bc4a60345928987481cec991d1a [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:52.482352 21759 raft_consensus.cc:493] T 00000000000000000000000000000000 P 85d10bc4a60345928987481cec991d1a [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:52.482440 21759 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 85d10bc4a60345928987481cec991d1a [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:52.483078 21759 raft_consensus.cc:515] T 00000000000000000000000000000000 P 85d10bc4a60345928987481cec991d1a [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "85d10bc4a60345928987481cec991d1a" member_type: VOTER }
I20260812 06:16:52.483440 21759 leader_election.cc:304] T 00000000000000000000000000000000 P 85d10bc4a60345928987481cec991d1a [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: 85d10bc4a60345928987481cec991d1a; no voters: 
I20260812 06:16:52.483669 21759 leader_election.cc:290] T 00000000000000000000000000000000 P 85d10bc4a60345928987481cec991d1a [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:52.483770 21768 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 85d10bc4a60345928987481cec991d1a [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:52.483974 21768 raft_consensus.cc:697] T 00000000000000000000000000000000 P 85d10bc4a60345928987481cec991d1a [term 1 LEADER]: Becoming Leader. State: Replica: 85d10bc4a60345928987481cec991d1a, State: Running, Role: LEADER
I20260812 06:16:52.484370 21768 consensus_queue.cc:237] T 00000000000000000000000000000000 P 85d10bc4a60345928987481cec991d1a [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: "85d10bc4a60345928987481cec991d1a" member_type: VOTER }
I20260812 06:16:52.484537 21759 sys_catalog.cc:565] T 00000000000000000000000000000000 P 85d10bc4a60345928987481cec991d1a [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:52.486111 21769 sys_catalog.cc:455] T 00000000000000000000000000000000 P 85d10bc4a60345928987481cec991d1a [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "85d10bc4a60345928987481cec991d1a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "85d10bc4a60345928987481cec991d1a" member_type: VOTER } }
I20260812 06:16:52.486150 21771 sys_catalog.cc:455] T 00000000000000000000000000000000 P 85d10bc4a60345928987481cec991d1a [sys.catalog]: SysCatalogTable state changed. Reason: New leader 85d10bc4a60345928987481cec991d1a. Latest consensus state: current_term: 1 leader_uuid: "85d10bc4a60345928987481cec991d1a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "85d10bc4a60345928987481cec991d1a" member_type: VOTER } }
I20260812 06:16:52.486213 21769 sys_catalog.cc:458] T 00000000000000000000000000000000 P 85d10bc4a60345928987481cec991d1a [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:52.486244 21771 sys_catalog.cc:458] T 00000000000000000000000000000000 P 85d10bc4a60345928987481cec991d1a [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:52.486631 21636 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:16:52.488358 21810 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 85d10bc4a60345928987481cec991d1a: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:16:52.488415 21810 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:16:52.488510 21806 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:52.489198 21806 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:52.493472 21806 catalog_manager.cc:1383] Generated new cluster ID: 46894b925aee43f1871670d89334af14
I20260812 06:16:52.493530 21806 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:52.509684 21806 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:52.510736 21806 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:52.518918 21806 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 85d10bc4a60345928987481cec991d1a: Generated new TSK 0
I20260812 06:16:52.519447 21806 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:52.551213 21636 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:52.553860 21822 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:52.554073 21636 server_base.cc:1061] running on GCE node
W20260812 06:16:52.554104 21825 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:52.553859 21820 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:52.554382 21636 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:52.554425 21636 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:52.554445 21636 hybrid_clock.cc:648] HybridClock initialized: now 1786515412554445 us; error 0 us; skew 500 ppm
I20260812 06:16:52.555310 21636 webserver.cc:533] Webserver started at http://127.21.33.1:41549/ using document root <none> and password file <none>
I20260812 06:16:52.555459 21636 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:52.555507 21636 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:52.555580 21636 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:52.555919 21636 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412404881-21636-0/minicluster-data/ts-0-root/instance:
uuid: "04a08cd6085546b8b0b6d1a71ef5a374"
format_stamp: "Formatted at 2026-08-12 06:16:52 on dist-test-slave-tc2s"
I20260812 06:16:52.557268 21636 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:16:52.558162 21840 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:52.558406 21636 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:52.558475 21636 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412404881-21636-0/minicluster-data/ts-0-root
uuid: "04a08cd6085546b8b0b6d1a71ef5a374"
format_stamp: "Formatted at 2026-08-12 06:16:52 on dist-test-slave-tc2s"
I20260812 06:16:52.558539 21636 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412404881-21636-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412404881-21636-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412404881-21636-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:52.564301 21636 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:52.564621 21636 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:52.564996 21636 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:52.565732 21636 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:52.565783 21636 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:52.565832 21636 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:52.565858 21636 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:52.571998 21636 rpc_server.cc:307] RPC server started. Bound to: 127.21.33.1:33063
I20260812 06:16:52.572059 21964 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.21.33.1:33063 every 8 connection(s)
I20260812 06:16:52.583731 21965 heartbeater.cc:344] Connected to a master server at 127.21.33.62:44943
I20260812 06:16:52.583935 21965 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:52.584301 21965 heartbeater.cc:507] Master 127.21.33.62:44943 requested a full tablet report, sending...
I20260812 06:16:52.585716 21689 ts_manager.cc:194] Registered new tserver with Master: 04a08cd6085546b8b0b6d1a71ef5a374 (127.21.33.1:33063)
I20260812 06:16:52.585814 21636 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.013261891s
I20260812 06:16:52.587113 21689 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:50642
I20260812 06:16:52.593557 21689 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:50652:
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:52.605777 21899 tablet_service.cc:1511] Processing CreateTablet for tablet 631cde22ce574e289ef1f220fd8e493f (DEFAULT_TABLE table=heavy-update-compaction-test [id=68b3c5cf48fa42ce92c7382f6acbded4]), partition=
I20260812 06:16:52.606160 21899 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 631cde22ce574e289ef1f220fd8e493f. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:52.608281 21996 tablet_bootstrap.cc:492] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374: Bootstrap starting.
I20260812 06:16:52.609499 21996 tablet_bootstrap.cc:654] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:52.610673 21996 tablet_bootstrap.cc:492] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374: No bootstrap required, opened a new log
I20260812 06:16:52.610774 21996 ts_tablet_manager.cc:1403] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:16:52.611224 21996 raft_consensus.cc:359] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "04a08cd6085546b8b0b6d1a71ef5a374" member_type: VOTER last_known_addr { host: "127.21.33.1" port: 33063 } }
I20260812 06:16:52.611339 21996 raft_consensus.cc:385] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:52.611390 21996 raft_consensus.cc:740] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 04a08cd6085546b8b0b6d1a71ef5a374, State: Initialized, Role: FOLLOWER
I20260812 06:16:52.611515 21996 consensus_queue.cc:260] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374 [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: "04a08cd6085546b8b0b6d1a71ef5a374" member_type: VOTER last_known_addr { host: "127.21.33.1" port: 33063 } }
I20260812 06:16:52.611610 21996 raft_consensus.cc:399] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:52.611654 21996 raft_consensus.cc:493] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:52.611702 21996 raft_consensus.cc:3060] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:52.612917 21996 raft_consensus.cc:515] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "04a08cd6085546b8b0b6d1a71ef5a374" member_type: VOTER last_known_addr { host: "127.21.33.1" port: 33063 } }
I20260812 06:16:52.613063 21996 leader_election.cc:304] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374 [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: 04a08cd6085546b8b0b6d1a71ef5a374; no voters: 
I20260812 06:16:52.613252 21996 leader_election.cc:290] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:52.613366 22003 raft_consensus.cc:2804] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:52.613617 22003 raft_consensus.cc:697] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374 [term 1 LEADER]: Becoming Leader. State: Replica: 04a08cd6085546b8b0b6d1a71ef5a374, State: Running, Role: LEADER
I20260812 06:16:52.613795 22003 consensus_queue.cc:237] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374 [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: "04a08cd6085546b8b0b6d1a71ef5a374" member_type: VOTER last_known_addr { host: "127.21.33.1" port: 33063 } }
I20260812 06:16:52.614095 21996 ts_tablet_manager.cc:1434] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:16:52.614567 21965 heartbeater.cc:499] Master 127.21.33.62:44943 was elected leader, sending a full tablet report...
I20260812 06:16:52.617090 21689 catalog_manager.cc:5719] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374 reported cstate change: term changed from 0 to 1, leader changed from <none> to 04a08cd6085546b8b0b6d1a71ef5a374 (127.21.33.1). New cstate: current_term: 1 leader_uuid: "04a08cd6085546b8b0b6d1a71ef5a374" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "04a08cd6085546b8b0b6d1a71ef5a374" member_type: VOTER last_known_addr { host: "127.21.33.1" port: 33063 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:52.679713 21636 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.053s	user 0.016s	sys 0.008s
I20260812 06:16:52.823037 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling FlushMRSOp(631cde22ce574e289ef1f220fd8e493f): perf score=19.054940
I20260812 06:16:52.981284 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: FlushMRSOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.158s	user 0.105s	sys 0.049s Metrics: {"bytes_written":12717739,"cfile_init":1,"compiler_manager_pool.queue_time_us":213,"delete_count":0,"dirs.queue_time_us":61,"dirs.run_cpu_time_us":183,"dirs.run_wall_time_us":832,"drs_written":1,"lbm_read_time_us":88,"lbm_reads_lt_1ms":4,"lbm_write_time_us":38938,"lbm_writes_lt_1ms":777,"mutex_wait_us":1205,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"spinlock_wait_cycles":238464,"thread_start_us":111,"threads_started":1,"update_count":1550}
I20260812 06:16:52.982283 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling LogGCOp(631cde22ce574e289ef1f220fd8e493f): free 20743880 bytes of WAL
I20260812 06:16:52.982535 21850 log_reader.cc:385] T 631cde22ce574e289ef1f220fd8e493f: removed 2 log segments from log reader
I20260812 06:16:52.982589 21850 log.cc:1079] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/631cde22ce574e289ef1f220fd8e493f/wal-000000001 (ops 1-6)
I20260812 06:16:52.982681 21850 log.cc:1079] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/631cde22ce574e289ef1f220fd8e493f/wal-000000002 (ops 7-11)
I20260812 06:16:52.987354 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: LogGCOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.005s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:16:52.987776 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f): perf score=2.188937
I20260812 06:16:53.001101 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.013s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3282155,"delete_count":0,"lbm_write_time_us":4233,"lbm_writes_lt_1ms":83,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":400}
I20260812 06:16:53.001662 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling UndoDeltaBlockGCOp(631cde22ce574e289ef1f220fd8e493f): 16821648 bytes on disk
I20260812 06:16:53.002231 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: UndoDeltaBlockGCOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4}
I20260812 06:16:53.002630 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling MajorDeltaCompactionOp(631cde22ce574e289ef1f220fd8e493f): perf score=1.000000
I20260812 06:16:53.140663 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: MajorDeltaCompactionOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.138s	user 0.111s	sys 0.023s Metrics: {"cfile_cache_miss":422,"cfile_cache_miss_bytes":20303017,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":485,"lbm_read_time_us":7836,"lbm_reads_lt_1ms":450,"lbm_write_time_us":21773,"lbm_writes_lt_1ms":433,"peak_mem_usage":49238594,"reinsert_count":0,"thread_start_us":403,"threads_started":5,"update_count":1950}
I20260812 06:16:53.141361 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f): perf score=10.126437
I20260812 06:16:53.169703 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.028s	user 0.022s	sys 0.003s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12206,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:53.170104 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f): perf score=2.188937
I20260812 06:16:53.182490 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4436,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:53.183029 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling MajorDeltaCompactionOp(631cde22ce574e289ef1f220fd8e493f): perf score=1.000000
I20260812 06:16:53.309940 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: MajorDeltaCompactionOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.127s	user 0.103s	sys 0.023s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":364,"lbm_read_time_us":8893,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23817,"lbm_writes_lt_1ms":443,"mutex_wait_us":59,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2000}
I20260812 06:16:53.316458 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f): perf score=10.126437
I20260812 06:16:53.353502 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.037s	user 0.015s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14447,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:53.354039 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f): perf score=2.188937
I20260812 06:16:53.369596 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5950,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:53.370117 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling MajorDeltaCompactionOp(631cde22ce574e289ef1f220fd8e493f): perf score=1.000000
I20260812 06:16:53.494674 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: MajorDeltaCompactionOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.124s	user 0.104s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":455,"lbm_read_time_us":9719,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22500,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:16:53.495350 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f): perf score=10.126437
I20260812 06:16:53.532529 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.037s	user 0.013s	sys 0.020s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":12104,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:53.533053 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f): perf score=2.188937
I20260812 06:16:53.543331 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3903,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:53.543721 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling MajorDeltaCompactionOp(631cde22ce574e289ef1f220fd8e493f): perf score=1.000000
I20260812 06:16:53.677009 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: MajorDeltaCompactionOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.133s	user 0.085s	sys 0.048s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":84,"lbm_read_time_us":11076,"lbm_reads_lt_1ms":472,"lbm_write_time_us":19725,"lbm_writes_lt_1ms":443,"mutex_wait_us":18,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9344,"update_count":2000}
I20260812 06:16:53.677549 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f): perf score=10.126437
I20260812 06:16:53.718905 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.041s	user 0.022s	sys 0.008s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":13376,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:53.719316 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f): perf score=2.188937
I20260812 06:16:53.728801 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3715,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:53.729276 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling MajorDeltaCompactionOp(631cde22ce574e289ef1f220fd8e493f): perf score=1.000000
I20260812 06:16:53.849582 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: MajorDeltaCompactionOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.120s	user 0.111s	sys 0.007s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713274,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":133,"lbm_read_time_us":8691,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22989,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:16:53.850078 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f): perf score=10.126437
I20260812 06:16:53.892047 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.042s	user 0.017s	sys 0.012s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":13508,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:53.892526 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f): perf score=2.188937
I20260812 06:16:53.901794 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3545,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:53.902210 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling MajorDeltaCompactionOp(631cde22ce574e289ef1f220fd8e493f): perf score=1.000000
I20260812 06:16:54.012296 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: MajorDeltaCompactionOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.110s	user 0.094s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713274,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":187,"lbm_read_time_us":7288,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21770,"lbm_writes_lt_1ms":443,"mutex_wait_us":39,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2000}
I20260812 06:16:54.012773 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f): perf score=10.126437
I20260812 06:16:54.052591 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.040s	user 0.022s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14023,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:54.053112 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f): perf score=2.188937
I20260812 06:16:54.062917 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3777,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:54.063313 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling MajorDeltaCompactionOp(631cde22ce574e289ef1f220fd8e493f): perf score=1.000000
I20260812 06:16:54.190459 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: MajorDeltaCompactionOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.127s	user 0.111s	sys 0.015s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":262,"lbm_read_time_us":8379,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24650,"lbm_writes_lt_1ms":443,"mutex_wait_us":33,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":44928,"update_count":2000}
I20260812 06:16:54.190927 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f): perf score=10.126437
I20260812 06:16:54.237964 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.047s	user 0.027s	sys 0.015s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":15135,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:54.238368 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f): perf score=2.188937
I20260812 06:16:54.247781 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3713,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:54.248142 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling FlushMRSOp(631cde22ce574e289ef1f220fd8e493f): perf score=1.000000
I20260812 06:16:54.276973 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: FlushMRSOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.029s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1275444,"cfile_init":1,"dirs.queue_time_us":48,"dirs.run_cpu_time_us":210,"dirs.run_wall_time_us":1117,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1373,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:16:54.277768 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling MajorDeltaCompactionOp(631cde22ce574e289ef1f220fd8e493f): perf score=1.000000
I20260812 06:16:54.408771 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: MajorDeltaCompactionOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.131s	user 0.087s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":176,"lbm_read_time_us":7913,"lbm_reads_lt_1ms":464,"lbm_write_time_us":21555,"lbm_writes_lt_1ms":443,"mutex_wait_us":2,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:16:54.409276 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling LogGCOp(631cde22ce574e289ef1f220fd8e493f): free 124710293 bytes of WAL
I20260812 06:16:54.409509 21850 log_reader.cc:385] T 631cde22ce574e289ef1f220fd8e493f: removed 12 log segments from log reader
I20260812 06:16:54.409569 21850 log.cc:1079] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/631cde22ce574e289ef1f220fd8e493f/wal-000000003 (ops 12-16)
I20260812 06:16:54.409607 21850 log.cc:1079] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/631cde22ce574e289ef1f220fd8e493f/wal-000000004 (ops 17-21)
I20260812 06:16:54.409637 21850 log.cc:1079] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/631cde22ce574e289ef1f220fd8e493f/wal-000000005 (ops 22-26)
I20260812 06:16:54.409667 21850 log.cc:1079] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/631cde22ce574e289ef1f220fd8e493f/wal-000000006 (ops 27-31)
I20260812 06:16:54.409696 21850 log.cc:1079] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/631cde22ce574e289ef1f220fd8e493f/wal-000000007 (ops 32-36)
I20260812 06:16:54.409725 21850 log.cc:1079] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/631cde22ce574e289ef1f220fd8e493f/wal-000000008 (ops 37-41)
I20260812 06:16:54.409755 21850 log.cc:1079] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/631cde22ce574e289ef1f220fd8e493f/wal-000000009 (ops 42-46)
I20260812 06:16:54.409785 21850 log.cc:1079] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/631cde22ce574e289ef1f220fd8e493f/wal-000000010 (ops 47-51)
I20260812 06:16:54.409813 21850 log.cc:1079] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/631cde22ce574e289ef1f220fd8e493f/wal-000000011 (ops 52-56)
I20260812 06:16:54.409843 21850 log.cc:1079] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/631cde22ce574e289ef1f220fd8e493f/wal-000000012 (ops 57-61)
I20260812 06:16:54.409871 21850 log.cc:1079] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/631cde22ce574e289ef1f220fd8e493f/wal-000000013 (ops 62-66)
I20260812 06:16:54.409927 21850 log.cc:1079] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/631cde22ce574e289ef1f220fd8e493f/wal-000000014 (ops 67-71)
I20260812 06:16:54.430150 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: LogGCOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.021s	user 0.001s	sys 0.019s Metrics: {}
I20260812 06:16:54.430603 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling UndoDeltaBlockGCOp(631cde22ce574e289ef1f220fd8e493f): 482 bytes on disk
I20260812 06:16:54.431056 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: UndoDeltaBlockGCOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4}
I20260812 06:16:54.431672 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f): perf score=14.095187
I20260812 06:16:54.473738 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.042s	user 0.030s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17886,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:54.474279 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f): perf score=2.188937
I20260812 06:16:54.505290 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.030s	user 0.013s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4834,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:54.505704 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f): perf score=2.188937
I20260812 06:16:54.515219 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3688,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:54.515619 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling MajorDeltaCompactionOp(631cde22ce574e289ef1f220fd8e493f): perf score=1.000000
I20260812 06:16:54.710783 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: MajorDeltaCompactionOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.195s	user 0.139s	sys 0.048s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918212,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":602,"lbm_read_time_us":13742,"lbm_reads_lt_1ms":673,"lbm_write_time_us":32954,"lbm_writes_lt_1ms":643,"mutex_wait_us":32,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":3000}
I20260812 06:16:54.711223 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f): perf score=14.095187
I20260812 06:16:54.763964 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.053s	user 0.016s	sys 0.029s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":16286,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:54.764516 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f): perf score=2.188937
I20260812 06:16:54.774120 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.009s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3715,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:54.774550 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling MajorDeltaCompactionOp(631cde22ce574e289ef1f220fd8e493f): perf score=1.000000
I20260812 06:16:54.937271 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: MajorDeltaCompactionOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.163s	user 0.129s	sys 0.033s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":590,"lbm_read_time_us":11686,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27495,"lbm_writes_lt_1ms":543,"mutex_wait_us":57,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:16:54.937976 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f): perf score=10.126437
I20260812 06:16:54.965600 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.027s	user 0.021s	sys 0.004s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":11845,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:54.966065 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f): perf score=2.188937
I20260812 06:16:54.978786 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.013s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3518,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:54.979305 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling MajorDeltaCompactionOp(631cde22ce574e289ef1f220fd8e493f): perf score=1.000000
I20260812 06:16:55.095059 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: MajorDeltaCompactionOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.115s	user 0.087s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713274,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":668,"lbm_read_time_us":6861,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21701,"lbm_writes_lt_1ms":443,"mutex_wait_us":26,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13568,"update_count":2000}
I20260812 06:16:55.095516 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f): perf score=10.126437
I20260812 06:16:55.132048 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.036s	user 0.025s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13248,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:55.132516 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f): perf score=2.188937
I20260812 06:16:55.142131 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.009s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3589,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:55.142604 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling MajorDeltaCompactionOp(631cde22ce574e289ef1f220fd8e493f): perf score=1.000000
I20260812 06:16:55.262349 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: MajorDeltaCompactionOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.120s	user 0.099s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1054,"lbm_read_time_us":9734,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21677,"lbm_writes_lt_1ms":443,"mutex_wait_us":442,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:16:55.262789 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f): perf score=10.126437
I20260812 06:16:55.302989 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.040s	user 0.022s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13635,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:55.303490 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f): perf score=2.188937
I20260812 06:16:55.321053 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.017s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5237,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:55.321552 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling MajorDeltaCompactionOp(631cde22ce574e289ef1f220fd8e493f): perf score=1.000000
I20260812 06:16:55.442366 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: MajorDeltaCompactionOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.121s	user 0.092s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1089,"lbm_read_time_us":9640,"lbm_reads_lt_1ms":468,"lbm_write_time_us":21973,"lbm_writes_lt_1ms":443,"mutex_wait_us":316,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3968,"update_count":2000}
I20260812 06:16:55.442800 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f): perf score=10.126437
I20260812 06:16:55.487498 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.045s	user 0.015s	sys 0.028s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16637,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:55.488039 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f): perf score=2.188937
I20260812 06:16:55.498301 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3953,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:55.498780 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling MajorDeltaCompactionOp(631cde22ce574e289ef1f220fd8e493f): perf score=1.000000
I20260812 06:16:55.632089 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: MajorDeltaCompactionOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.133s	user 0.085s	sys 0.048s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":612,"lbm_read_time_us":10359,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21948,"lbm_writes_lt_1ms":443,"mutex_wait_us":27,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":2000}
I20260812 06:16:55.632623 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f): perf score=10.126437
I20260812 06:16:55.676846 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.044s	user 0.024s	sys 0.007s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15093,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:55.677332 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f): perf score=2.188937
I20260812 06:16:55.691907 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.014s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5431,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:55.692828 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling FlushMRSOp(631cde22ce574e289ef1f220fd8e493f): perf score=1.000000
I20260812 06:16:55.720021 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: FlushMRSOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.027s	user 0.022s	sys 0.003s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":57,"dirs.run_cpu_time_us":202,"dirs.run_wall_time_us":1038,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1831,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:16:55.720774 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling LogGCOp(631cde22ce574e289ef1f220fd8e493f): free 132571338 bytes of WAL
I20260812 06:16:55.721009 21850 log_reader.cc:385] T 631cde22ce574e289ef1f220fd8e493f: removed 13 log segments from log reader
I20260812 06:16:55.721065 21850 log.cc:1079] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/631cde22ce574e289ef1f220fd8e493f/wal-000000015 (ops 72-76)
I20260812 06:16:55.721101 21850 log.cc:1079] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/631cde22ce574e289ef1f220fd8e493f/wal-000000016 (ops 77-81)
I20260812 06:16:55.721133 21850 log.cc:1079] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/631cde22ce574e289ef1f220fd8e493f/wal-000000017 (ops 82-86)
I20260812 06:16:55.721165 21850 log.cc:1079] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/631cde22ce574e289ef1f220fd8e493f/wal-000000018 (ops 87-91)
I20260812 06:16:55.721190 21850 log.cc:1079] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/631cde22ce574e289ef1f220fd8e493f/wal-000000019 (ops 92-96)
I20260812 06:16:55.721220 21850 log.cc:1079] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/631cde22ce574e289ef1f220fd8e493f/wal-000000020 (ops 97-100)
I20260812 06:16:55.721251 21850 log.cc:1079] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/631cde22ce574e289ef1f220fd8e493f/wal-000000021 (ops 101-105)
I20260812 06:16:55.721282 21850 log.cc:1079] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/631cde22ce574e289ef1f220fd8e493f/wal-000000022 (ops 106-110)
I20260812 06:16:55.721312 21850 log.cc:1079] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/631cde22ce574e289ef1f220fd8e493f/wal-000000023 (ops 111-115)
I20260812 06:16:55.721364 21850 log.cc:1079] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/631cde22ce574e289ef1f220fd8e493f/wal-000000024 (ops 116-120)
I20260812 06:16:55.721395 21850 log.cc:1079] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/631cde22ce574e289ef1f220fd8e493f/wal-000000025 (ops 121-125)
I20260812 06:16:55.721426 21850 log.cc:1079] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/631cde22ce574e289ef1f220fd8e493f/wal-000000026 (ops 126-130)
I20260812 06:16:55.721457 21850 log.cc:1079] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/631cde22ce574e289ef1f220fd8e493f/wal-000000027 (ops 131-134)
I20260812 06:16:55.745085 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: LogGCOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.024s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:16:55.745512 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f): perf score=3.181125
I20260812 06:16:55.763145 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.017s	user 0.002s	sys 0.014s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":4369,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:55.763581 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling UndoDeltaBlockGCOp(631cde22ce574e289ef1f220fd8e493f): 482 bytes on disk
I20260812 06:16:55.763965 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: UndoDeltaBlockGCOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:16:55.764496 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f): perf score=2.188937
I20260812 06:16:55.773480 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.009s	user 0.003s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3555,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:55.773950 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling MajorDeltaCompactionOp(631cde22ce574e289ef1f220fd8e493f): perf score=1.000000
I20260812 06:16:55.972808 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: MajorDeltaCompactionOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.199s	user 0.133s	sys 0.065s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918324,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":808,"lbm_read_time_us":14331,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34022,"lbm_writes_lt_1ms":643,"mutex_wait_us":281,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3200,"thread_start_us":72,"threads_started":1,"update_count":3000}
I20260812 06:16:55.973336 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f): perf score=14.095187
I20260812 06:16:56.027787 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.054s	user 0.025s	sys 0.023s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":17678,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:56.028223 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f): perf score=2.188937
I20260812 06:16:56.037848 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3749,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:56.038281 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling MajorDeltaCompactionOp(631cde22ce574e289ef1f220fd8e493f): perf score=1.000000
I20260812 06:16:56.203228 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: MajorDeltaCompactionOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.165s	user 0.113s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":224,"lbm_read_time_us":11274,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26631,"lbm_writes_lt_1ms":543,"mutex_wait_us":1,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8448,"update_count":2500}
I20260812 06:16:56.203908 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f): perf score=11.118625
I20260812 06:16:56.239318 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.035s	user 0.014s	sys 0.019s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14978,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:56.239840 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f): perf score=2.188937
I20260812 06:16:56.255715 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.016s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6648,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":92,"reinsert_count":0,"update_count":450}
I20260812 06:16:56.256134 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling MajorDeltaCompactionOp(631cde22ce574e289ef1f220fd8e493f): perf score=1.000000
I20260812 06:16:56.377987 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: MajorDeltaCompactionOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.122s	user 0.101s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713263,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":899,"lbm_read_time_us":8293,"lbm_reads_lt_1ms":464,"lbm_write_time_us":21697,"lbm_writes_lt_1ms":443,"mutex_wait_us":318,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":34048,"update_count":2000}
I20260812 06:16:56.378475 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f): perf score=10.126437
I20260812 06:16:56.416533 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.038s	user 0.021s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15308,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:16:56.417101 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f): perf score=2.188937
I20260812 06:16:56.430359 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.013s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4577,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:56.430918 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling MajorDeltaCompactionOp(631cde22ce574e289ef1f220fd8e493f): perf score=1.000000
I20260812 06:16:56.557961 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: MajorDeltaCompactionOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.127s	user 0.103s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":572,"lbm_read_time_us":9168,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24174,"lbm_writes_lt_1ms":443,"mutex_wait_us":279,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":38912,"update_count":2000}
I20260812 06:16:56.558449 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f): perf score=10.126437
I20260812 06:16:56.598615 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.040s	user 0.019s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14873,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:56.599216 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f): perf score=2.188937
I20260812 06:16:56.613653 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5197,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:56.614169 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling MajorDeltaCompactionOp(631cde22ce574e289ef1f220fd8e493f): perf score=1.000000
I20260812 06:16:56.739583 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: MajorDeltaCompactionOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.125s	user 0.103s	sys 0.021s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":582,"lbm_read_time_us":10687,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23204,"lbm_writes_lt_1ms":443,"mutex_wait_us":40,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3328,"update_count":2000}
I20260812 06:16:56.740010 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f): perf score=10.126437
I20260812 06:16:56.778047 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.038s	user 0.021s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12371,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:56.778916 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling MajorDeltaCompactionOp(631cde22ce574e289ef1f220fd8e493f): perf score=1.000000
I20260812 06:16:56.895591 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: MajorDeltaCompactionOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.117s	user 0.082s	sys 0.033s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16610741,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":296,"lbm_read_time_us":7548,"lbm_reads_lt_1ms":363,"lbm_write_time_us":17814,"lbm_writes_lt_1ms":343,"mutex_wait_us":41,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":632832,"update_count":1500}
I20260812 06:16:56.896095 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f): perf score=10.126437
I20260812 06:16:56.936550 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.040s	user 0.025s	sys 0.012s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":18105,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:16:56.937049 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f): perf score=2.188937
I20260812 06:16:56.947197 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.010s	user 0.000s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3648,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:56.948432 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling MajorDeltaCompactionOp(631cde22ce574e289ef1f220fd8e493f): perf score=1.000000
I20260812 06:16:57.073123 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: MajorDeltaCompactionOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.124s	user 0.087s	sys 0.037s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":637,"lbm_read_time_us":9562,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22923,"lbm_writes_lt_1ms":443,"mutex_wait_us":254,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:16:57.073652 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f): perf score=10.126437
I20260812 06:16:57.112869 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.039s	user 0.025s	sys 0.000s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12183,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:57.113343 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f): perf score=2.188937
I20260812 06:16:57.122850 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3657,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:57.123296 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling FlushMRSOp(631cde22ce574e289ef1f220fd8e493f): perf score=1.000000
I20260812 06:16:57.155830 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: FlushMRSOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.032s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1234477,"cfile_init":1,"dirs.queue_time_us":57,"dirs.run_cpu_time_us":213,"dirs.run_wall_time_us":1092,"drs_written":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1593,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:16:57.156476 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling LogGCOp(631cde22ce574e289ef1f220fd8e493f): free 129320724 bytes of WAL
I20260812 06:16:57.156689 21850 log_reader.cc:385] T 631cde22ce574e289ef1f220fd8e493f: removed 13 log segments from log reader
I20260812 06:16:57.156734 21850 log.cc:1079] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/631cde22ce574e289ef1f220fd8e493f/wal-000000028 (ops 135-139)
I20260812 06:16:57.156761 21850 log.cc:1079] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/631cde22ce574e289ef1f220fd8e493f/wal-000000029 (ops 140-144)
I20260812 06:16:57.156792 21850 log.cc:1079] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/631cde22ce574e289ef1f220fd8e493f/wal-000000030 (ops 145-149)
I20260812 06:16:57.156822 21850 log.cc:1079] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/631cde22ce574e289ef1f220fd8e493f/wal-000000031 (ops 150-154)
I20260812 06:16:57.156854 21850 log.cc:1079] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/631cde22ce574e289ef1f220fd8e493f/wal-000000032 (ops 155-159)
I20260812 06:16:57.156888 21850 log.cc:1079] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/631cde22ce574e289ef1f220fd8e493f/wal-000000033 (ops 160-164)
I20260812 06:16:57.156911 21850 log.cc:1079] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/631cde22ce574e289ef1f220fd8e493f/wal-000000034 (ops 165-169)
I20260812 06:16:57.156942 21850 log.cc:1079] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/631cde22ce574e289ef1f220fd8e493f/wal-000000035 (ops 170-174)
I20260812 06:16:57.156965 21850 log.cc:1079] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/631cde22ce574e289ef1f220fd8e493f/wal-000000036 (ops 175-178)
I20260812 06:16:57.156994 21850 log.cc:1079] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/631cde22ce574e289ef1f220fd8e493f/wal-000000037 (ops 179-183)
I20260812 06:16:57.157025 21850 log.cc:1079] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/631cde22ce574e289ef1f220fd8e493f/wal-000000038 (ops 184-188)
I20260812 06:16:57.157055 21850 log.cc:1079] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/631cde22ce574e289ef1f220fd8e493f/wal-000000039 (ops 189-192)
I20260812 06:16:57.157088 21850 log.cc:1079] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/631cde22ce574e289ef1f220fd8e493f/wal-000000040 (ops 193-197)
I20260812 06:16:57.181671 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: LogGCOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.025s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:16:57.182155 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling UndoDeltaBlockGCOp(631cde22ce574e289ef1f220fd8e493f): 473 bytes on disk
I20260812 06:16:57.182624 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: UndoDeltaBlockGCOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":77,"lbm_reads_lt_1ms":4}
I20260812 06:16:57.183310 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f): perf score=4.173312
I20260812 06:16:57.200253 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.017s	user 0.011s	sys 0.004s Metrics: {"bytes_written":5374417,"delete_count":0,"lbm_write_time_us":6943,"lbm_writes_lt_1ms":134,"reinsert_count":0,"update_count":655}
I20260812 06:16:57.200624 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f): perf score=1.196750
I20260812 06:16:57.207657 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: FlushDeltaMemStoresOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.007s	user 0.006s	sys 0.000s Metrics: {"bytes_written":2830880,"delete_count":0,"lbm_write_time_us":2449,"lbm_writes_lt_1ms":72,"reinsert_count":0,"update_count":345}
I20260812 06:16:57.208021 21967 maintenance_manager.cc:419] P 04a08cd6085546b8b0b6d1a71ef5a374: Scheduling MajorDeltaCompactionOp(631cde22ce574e289ef1f220fd8e493f): perf score=1.000000
I20260812 06:16:57.241255 21636 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.561s	user 1.647s	sys 0.150s
I20260812 06:16:57.318990 21636 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.077s	user 0.002s	sys 0.000s
I20260812 06:16:57.319598 21636 tablet_server.cc:179] TabletServer@127.21.33.1:0 shutting down...
I20260812 06:16:57.363854 21850 maintenance_manager.cc:643] P 04a08cd6085546b8b0b6d1a71ef5a374: MajorDeltaCompactionOp(631cde22ce574e289ef1f220fd8e493f) complete. Timing: real 0.156s	user 0.120s	sys 0.036s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918306,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":425,"lbm_read_time_us":13271,"lbm_reads_lt_1ms":670,"lbm_write_time_us":27076,"lbm_writes_lt_1ms":643,"mutex_wait_us":53,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3328,"thread_start_us":70,"threads_started":1,"update_count":3000}
I20260812 06:16:57.364557 21636 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:16:57.365088 21636 tablet_replica.cc:333] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374: stopping tablet replica
I20260812 06:16:57.365329 21636 raft_consensus.cc:2243] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:57.365581 21636 raft_consensus.cc:2272] T 631cde22ce574e289ef1f220fd8e493f P 04a08cd6085546b8b0b6d1a71ef5a374 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:57.382361 21636 tablet_server.cc:196] TabletServer@127.21.33.1:0 shutdown complete.
I20260812 06:16:57.416898 21636 master.cc:562] Master@127.21.33.62:44943 shutting down...
I20260812 06:16:57.420037 21636 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 85d10bc4a60345928987481cec991d1a [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:57.420198 21636 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 85d10bc4a60345928987481cec991d1a [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:57.420252 21636 tablet_replica.cc:333] T 00000000000000000000000000000000 P 85d10bc4a60345928987481cec991d1a: stopping tablet replica
I20260812 06:16:57.432307 21636 master.cc:584] Master@127.21.33.62:44943 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5086 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:16:57.501204 21636 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.21.33.62:39913
I20260812 06:16:57.501569 21636 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:57.503721 22035 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:16:57.503814 22039 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:57.503794 22033 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:57.503922 21636 server_base.cc:1061] running on GCE node
I20260812 06:16:57.504195 21636 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:57.504236 21636 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:57.504251 21636 hybrid_clock.cc:648] HybridClock initialized: now 1786515417504250 us; error 0 us; skew 500 ppm
I20260812 06:16:57.505007 21636 webserver.cc:533] Webserver started at http://127.21.33.62:41201/ using document root <none> and password file <none>
I20260812 06:16:57.505151 21636 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:57.505195 21636 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:57.505270 21636 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:57.505640 21636 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412404881-21636-0/minicluster-data/master-0-root/instance:
uuid: "e15eb4d90ee94fab9f66b9a8b26001c8"
format_stamp: "Formatted at 2026-08-12 06:16:57 on dist-test-slave-tc2s"
I20260812 06:16:57.507076 21636 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:16:57.507918 22053 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:57.508112 21636 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:57.508176 21636 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412404881-21636-0/minicluster-data/master-0-root
uuid: "e15eb4d90ee94fab9f66b9a8b26001c8"
format_stamp: "Formatted at 2026-08-12 06:16:57 on dist-test-slave-tc2s"
I20260812 06:16:57.508236 21636 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412404881-21636-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412404881-21636-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412404881-21636-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:57.518541 21636 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:57.518832 21636 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:57.522575 21636 rpc_server.cc:307] RPC server started. Bound to: 127.21.33.62:39913
I20260812 06:16:57.531569 22161 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.21.33.62:39913 every 8 connection(s)
I20260812 06:16:57.532051 22162 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:57.533718 22162 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P e15eb4d90ee94fab9f66b9a8b26001c8: Bootstrap starting.
I20260812 06:16:57.534473 22162 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P e15eb4d90ee94fab9f66b9a8b26001c8: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:57.535462 22162 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P e15eb4d90ee94fab9f66b9a8b26001c8: No bootstrap required, opened a new log
I20260812 06:16:57.535848 22162 raft_consensus.cc:359] T 00000000000000000000000000000000 P e15eb4d90ee94fab9f66b9a8b26001c8 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e15eb4d90ee94fab9f66b9a8b26001c8" member_type: VOTER }
I20260812 06:16:57.535933 22162 raft_consensus.cc:385] T 00000000000000000000000000000000 P e15eb4d90ee94fab9f66b9a8b26001c8 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:57.535964 22162 raft_consensus.cc:740] T 00000000000000000000000000000000 P e15eb4d90ee94fab9f66b9a8b26001c8 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: e15eb4d90ee94fab9f66b9a8b26001c8, State: Initialized, Role: FOLLOWER
I20260812 06:16:57.536095 22162 consensus_queue.cc:260] T 00000000000000000000000000000000 P e15eb4d90ee94fab9f66b9a8b26001c8 [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: "e15eb4d90ee94fab9f66b9a8b26001c8" member_type: VOTER }
I20260812 06:16:57.536165 22162 raft_consensus.cc:399] T 00000000000000000000000000000000 P e15eb4d90ee94fab9f66b9a8b26001c8 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:57.536202 22162 raft_consensus.cc:493] T 00000000000000000000000000000000 P e15eb4d90ee94fab9f66b9a8b26001c8 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:57.536249 22162 raft_consensus.cc:3060] T 00000000000000000000000000000000 P e15eb4d90ee94fab9f66b9a8b26001c8 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:57.536943 22162 raft_consensus.cc:515] T 00000000000000000000000000000000 P e15eb4d90ee94fab9f66b9a8b26001c8 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e15eb4d90ee94fab9f66b9a8b26001c8" member_type: VOTER }
I20260812 06:16:57.537071 22162 leader_election.cc:304] T 00000000000000000000000000000000 P e15eb4d90ee94fab9f66b9a8b26001c8 [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: e15eb4d90ee94fab9f66b9a8b26001c8; no voters: 
I20260812 06:16:57.537240 22162 leader_election.cc:290] T 00000000000000000000000000000000 P e15eb4d90ee94fab9f66b9a8b26001c8 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:57.537374 22167 raft_consensus.cc:2804] T 00000000000000000000000000000000 P e15eb4d90ee94fab9f66b9a8b26001c8 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:57.537552 22167 raft_consensus.cc:697] T 00000000000000000000000000000000 P e15eb4d90ee94fab9f66b9a8b26001c8 [term 1 LEADER]: Becoming Leader. State: Replica: e15eb4d90ee94fab9f66b9a8b26001c8, State: Running, Role: LEADER
I20260812 06:16:57.537704 22162 sys_catalog.cc:565] T 00000000000000000000000000000000 P e15eb4d90ee94fab9f66b9a8b26001c8 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:57.537685 22167 consensus_queue.cc:237] T 00000000000000000000000000000000 P e15eb4d90ee94fab9f66b9a8b26001c8 [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: "e15eb4d90ee94fab9f66b9a8b26001c8" member_type: VOTER }
I20260812 06:16:57.538136 22170 sys_catalog.cc:455] T 00000000000000000000000000000000 P e15eb4d90ee94fab9f66b9a8b26001c8 [sys.catalog]: SysCatalogTable state changed. Reason: New leader e15eb4d90ee94fab9f66b9a8b26001c8. Latest consensus state: current_term: 1 leader_uuid: "e15eb4d90ee94fab9f66b9a8b26001c8" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e15eb4d90ee94fab9f66b9a8b26001c8" member_type: VOTER } }
I20260812 06:16:57.538118 22169 sys_catalog.cc:455] T 00000000000000000000000000000000 P e15eb4d90ee94fab9f66b9a8b26001c8 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "e15eb4d90ee94fab9f66b9a8b26001c8" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e15eb4d90ee94fab9f66b9a8b26001c8" member_type: VOTER } }
I20260812 06:16:57.538254 22170 sys_catalog.cc:458] T 00000000000000000000000000000000 P e15eb4d90ee94fab9f66b9a8b26001c8 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:57.538313 22169 sys_catalog.cc:458] T 00000000000000000000000000000000 P e15eb4d90ee94fab9f66b9a8b26001c8 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:57.538782 22174 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:57.539542 22174 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:57.539701 21636 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:16:57.541234 22174 catalog_manager.cc:1383] Generated new cluster ID: 05d0266521d44812948185762f789b3e
I20260812 06:16:57.541280 22174 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:57.547554 22174 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:57.548032 22174 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:57.555706 22174 catalog_manager.cc:6092] T 00000000000000000000000000000000 P e15eb4d90ee94fab9f66b9a8b26001c8: Generated new TSK 0
I20260812 06:16:57.555871 22174 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:57.571801 21636 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:57.574055 22197 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:57.574097 21636 server_base.cc:1061] running on GCE node
W20260812 06:16:57.574162 22195 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:57.574088 22200 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:57.574396 21636 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:57.574441 21636 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:57.574455 21636 hybrid_clock.cc:648] HybridClock initialized: now 1786515417574456 us; error 0 us; skew 500 ppm
I20260812 06:16:57.575181 21636 webserver.cc:533] Webserver started at http://127.21.33.1:46841/ using document root <none> and password file <none>
I20260812 06:16:57.575307 21636 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:57.575350 21636 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:57.575404 21636 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:57.575717 21636 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412404881-21636-0/minicluster-data/ts-0-root/instance:
uuid: "4f9c8096211d402fa46ce1ee5a4ed929"
format_stamp: "Formatted at 2026-08-12 06:16:57 on dist-test-slave-tc2s"
I20260812 06:16:57.577029 21636 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:57.577807 22208 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:57.578023 21636 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:57.578089 21636 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412404881-21636-0/minicluster-data/ts-0-root
uuid: "4f9c8096211d402fa46ce1ee5a4ed929"
format_stamp: "Formatted at 2026-08-12 06:16:57 on dist-test-slave-tc2s"
I20260812 06:16:57.578153 21636 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412404881-21636-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412404881-21636-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412404881-21636-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:57.620949 21636 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:57.621299 21636 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:57.621582 21636 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:57.622072 21636 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:57.622112 21636 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:57.622179 21636 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:57.622206 21636 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:57.626071 21636 rpc_server.cc:307] RPC server started. Bound to: 127.21.33.1:37875
I20260812 06:16:57.626257 22336 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.21.33.1:37875 every 8 connection(s)
I20260812 06:16:57.632884 22337 heartbeater.cc:344] Connected to a master server at 127.21.33.62:39913
I20260812 06:16:57.632977 22337 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:57.633167 22337 heartbeater.cc:507] Master 127.21.33.62:39913 requested a full tablet report, sending...
I20260812 06:16:57.633745 22091 ts_manager.cc:194] Registered new tserver with Master: 4f9c8096211d402fa46ce1ee5a4ed929 (127.21.33.1:37875)
I20260812 06:16:57.634176 21636 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.007654891s
I20260812 06:16:57.634478 22091 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:42990
I20260812 06:16:57.640240 22091 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:42992:
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:57.647912 22280 tablet_service.cc:1511] Processing CreateTablet for tablet 21a17be99f3e4b38b1657cf2c5686ebc (DEFAULT_TABLE table=heavy-update-compaction-test [id=520669eafc4c49aeaa6e6f2d32a7c6ed]), partition=
I20260812 06:16:57.648130 22280 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 21a17be99f3e4b38b1657cf2c5686ebc. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:57.649868 22359 tablet_bootstrap.cc:492] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929: Bootstrap starting.
I20260812 06:16:57.650787 22359 tablet_bootstrap.cc:654] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:57.651713 22359 tablet_bootstrap.cc:492] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929: No bootstrap required, opened a new log
I20260812 06:16:57.651785 22359 ts_tablet_manager.cc:1403] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929: Time spent bootstrapping tablet: real 0.002s	user 0.000s	sys 0.001s
I20260812 06:16:57.652159 22359 raft_consensus.cc:359] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4f9c8096211d402fa46ce1ee5a4ed929" member_type: VOTER last_known_addr { host: "127.21.33.1" port: 37875 } }
I20260812 06:16:57.652242 22359 raft_consensus.cc:385] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:57.652275 22359 raft_consensus.cc:740] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 4f9c8096211d402fa46ce1ee5a4ed929, State: Initialized, Role: FOLLOWER
I20260812 06:16:57.652401 22359 consensus_queue.cc:260] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929 [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: "4f9c8096211d402fa46ce1ee5a4ed929" member_type: VOTER last_known_addr { host: "127.21.33.1" port: 37875 } }
I20260812 06:16:57.652479 22359 raft_consensus.cc:399] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:57.652518 22359 raft_consensus.cc:493] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:57.652567 22359 raft_consensus.cc:3060] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:57.653244 22359 raft_consensus.cc:515] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4f9c8096211d402fa46ce1ee5a4ed929" member_type: VOTER last_known_addr { host: "127.21.33.1" port: 37875 } }
I20260812 06:16:57.653386 22359 leader_election.cc:304] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929 [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: 4f9c8096211d402fa46ce1ee5a4ed929; no voters: 
I20260812 06:16:57.653580 22359 leader_election.cc:290] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:57.653679 22365 raft_consensus.cc:2804] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:57.653863 22365 raft_consensus.cc:697] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929 [term 1 LEADER]: Becoming Leader. State: Replica: 4f9c8096211d402fa46ce1ee5a4ed929, State: Running, Role: LEADER
I20260812 06:16:57.653982 22337 heartbeater.cc:499] Master 127.21.33.62:39913 was elected leader, sending a full tablet report...
I20260812 06:16:57.654057 22365 consensus_queue.cc:237] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929 [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: "4f9c8096211d402fa46ce1ee5a4ed929" member_type: VOTER last_known_addr { host: "127.21.33.1" port: 37875 } }
I20260812 06:16:57.654182 22359 ts_tablet_manager.cc:1434] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:16:57.655208 22091 catalog_manager.cc:5719] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929 reported cstate change: term changed from 0 to 1, leader changed from <none> to 4f9c8096211d402fa46ce1ee5a4ed929 (127.21.33.1). New cstate: current_term: 1 leader_uuid: "4f9c8096211d402fa46ce1ee5a4ed929" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4f9c8096211d402fa46ce1ee5a4ed929" member_type: VOTER last_known_addr { host: "127.21.33.1" port: 37875 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:57.708575 21636 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.050s	user 0.017s	sys 0.005s
I20260812 06:16:57.876981 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling FlushMRSOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=23.023690
I20260812 06:16:58.027842 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: FlushMRSOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.151s	user 0.109s	sys 0.040s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":69,"dirs.run_cpu_time_us":236,"dirs.run_wall_time_us":926,"drs_written":1,"lbm_read_time_us":35,"lbm_reads_lt_1ms":4,"lbm_write_time_us":39615,"lbm_writes_lt_1ms":857,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":1500}
I20260812 06:16:58.028474 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling LogGCOp(21a17be99f3e4b38b1657cf2c5686ebc): free 20743880 bytes of WAL
I20260812 06:16:58.028733 22219 log_reader.cc:385] T 21a17be99f3e4b38b1657cf2c5686ebc: removed 2 log segments from log reader
I20260812 06:16:58.028815 22219 log.cc:1079] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/21a17be99f3e4b38b1657cf2c5686ebc/wal-000000001 (ops 1-6)
I20260812 06:16:58.028880 22219 log.cc:1079] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/21a17be99f3e4b38b1657cf2c5686ebc/wal-000000002 (ops 7-11)
I20260812 06:16:58.034072 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: LogGCOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.005s	user 0.000s	sys 0.005s Metrics: {}
I20260812 06:16:58.034379 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling UndoDeltaBlockGCOp(21a17be99f3e4b38b1657cf2c5686ebc): 20513813 bytes on disk
I20260812 06:16:58.034760 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: UndoDeltaBlockGCOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4}
I20260812 06:16:58.035130 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=2.188937
I20260812 06:16:58.053712 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.018s	user 0.008s	sys 0.002s Metrics: {"bytes_written":4102660,"delete_count":0,"lbm_write_time_us":4552,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":500}
I20260812 06:16:58.054168 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=2.188937
I20260812 06:16:58.063587 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3592,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:58.063943 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling MajorDeltaCompactionOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=1.000000
I20260812 06:16:58.225240 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: MajorDeltaCompactionOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.161s	user 0.112s	sys 0.040s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815803,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":406,"lbm_read_time_us":11425,"lbm_reads_lt_1ms":569,"lbm_write_time_us":28457,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2304,"thread_start_us":224,"threads_started":5,"update_count":2500}
I20260812 06:16:58.225662 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=14.095187
I20260812 06:16:58.270671 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.045s	user 0.021s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19931,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:16:58.271081 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=2.188937
I20260812 06:16:58.289274 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.018s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5018,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:58.289811 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling MajorDeltaCompactionOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=1.000000
I20260812 06:16:58.438161 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: MajorDeltaCompactionOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.148s	user 0.097s	sys 0.041s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":132,"lbm_read_time_us":10359,"lbm_reads_lt_1ms":564,"lbm_write_time_us":26998,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":23040,"update_count":2500}
I20260812 06:16:58.438761 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=14.095187
I20260812 06:16:58.496189 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.057s	user 0.029s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19293,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:58.496657 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=2.188937
I20260812 06:16:58.506438 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3604,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:58.507011 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling MajorDeltaCompactionOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=1.000000
I20260812 06:16:58.683820 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: MajorDeltaCompactionOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.177s	user 0.121s	sys 0.051s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":546,"lbm_read_time_us":12565,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27333,"lbm_writes_lt_1ms":543,"mutex_wait_us":278,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":42496,"update_count":2500}
I20260812 06:16:58.684278 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=14.095187
I20260812 06:16:58.726677 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.042s	user 0.030s	sys 0.011s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18701,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:58.727169 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling MajorDeltaCompactionOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=1.000000
I20260812 06:16:58.866657 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: MajorDeltaCompactionOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.139s	user 0.106s	sys 0.032s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713153,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":534,"lbm_read_time_us":10940,"lbm_reads_lt_1ms":467,"lbm_write_time_us":21337,"lbm_writes_lt_1ms":443,"mutex_wait_us":272,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6144,"update_count":2000}
I20260812 06:16:58.867259 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=11.118625
I20260812 06:16:58.906898 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.039s	user 0.014s	sys 0.019s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15054,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:16:58.907302 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=2.188937
I20260812 06:16:58.919823 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.012s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4048,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:58.920331 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=2.188937
I20260812 06:16:58.933581 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5181,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:58.934079 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling MajorDeltaCompactionOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=1.000000
I20260812 06:16:59.108690 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: MajorDeltaCompactionOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.174s	user 0.113s	sys 0.050s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815794,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":821,"lbm_read_time_us":9447,"lbm_reads_lt_1ms":573,"lbm_write_time_us":27760,"lbm_writes_lt_1ms":543,"mutex_wait_us":240,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8960,"update_count":2500}
I20260812 06:16:59.109176 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=14.095187
I20260812 06:16:59.153083 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.044s	user 0.028s	sys 0.012s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20619,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:16:59.153656 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=2.188937
I20260812 06:16:59.164194 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.010s	user 0.001s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3836,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:59.164685 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling FlushMRSOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=1.000000
I20260812 06:16:59.194617 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: FlushMRSOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.030s	user 0.028s	sys 0.001s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":47,"dirs.run_cpu_time_us":210,"dirs.run_wall_time_us":1123,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1525,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:16:59.195250 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling LogGCOp(21a17be99f3e4b38b1657cf2c5686ebc): free 121006426 bytes of WAL
I20260812 06:16:59.195482 22219 log_reader.cc:385] T 21a17be99f3e4b38b1657cf2c5686ebc: removed 12 log segments from log reader
I20260812 06:16:59.195529 22219 log.cc:1079] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/21a17be99f3e4b38b1657cf2c5686ebc/wal-000000003 (ops 12-16)
I20260812 06:16:59.195566 22219 log.cc:1079] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/21a17be99f3e4b38b1657cf2c5686ebc/wal-000000004 (ops 17-21)
I20260812 06:16:59.195600 22219 log.cc:1079] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/21a17be99f3e4b38b1657cf2c5686ebc/wal-000000005 (ops 22-26)
I20260812 06:16:59.195631 22219 log.cc:1079] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/21a17be99f3e4b38b1657cf2c5686ebc/wal-000000006 (ops 27-31)
I20260812 06:16:59.195662 22219 log.cc:1079] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/21a17be99f3e4b38b1657cf2c5686ebc/wal-000000007 (ops 32-36)
I20260812 06:16:59.195691 22219 log.cc:1079] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/21a17be99f3e4b38b1657cf2c5686ebc/wal-000000008 (ops 37-41)
I20260812 06:16:59.195720 22219 log.cc:1079] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/21a17be99f3e4b38b1657cf2c5686ebc/wal-000000009 (ops 42-46)
I20260812 06:16:59.195750 22219 log.cc:1079] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/21a17be99f3e4b38b1657cf2c5686ebc/wal-000000010 (ops 47-50)
I20260812 06:16:59.195779 22219 log.cc:1079] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/21a17be99f3e4b38b1657cf2c5686ebc/wal-000000011 (ops 51-55)
I20260812 06:16:59.195808 22219 log.cc:1079] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/21a17be99f3e4b38b1657cf2c5686ebc/wal-000000012 (ops 56-60)
I20260812 06:16:59.195838 22219 log.cc:1079] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/21a17be99f3e4b38b1657cf2c5686ebc/wal-000000013 (ops 61-65)
I20260812 06:16:59.195868 22219 log.cc:1079] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/21a17be99f3e4b38b1657cf2c5686ebc/wal-000000014 (ops 66-70)
I20260812 06:16:59.217257 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: LogGCOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.022s	user 0.000s	sys 0.019s Metrics: {}
I20260812 06:16:59.217792 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling UndoDeltaBlockGCOp(21a17be99f3e4b38b1657cf2c5686ebc): 463 bytes on disk
I20260812 06:16:59.218196 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: UndoDeltaBlockGCOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4}
I20260812 06:16:59.218586 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=2.188937
I20260812 06:16:59.232013 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.013s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4376,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:59.232424 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling MajorDeltaCompactionOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=1.000000
I20260812 06:16:59.427827 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: MajorDeltaCompactionOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.195s	user 0.138s	sys 0.052s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918216,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1349,"lbm_read_time_us":14656,"lbm_reads_lt_1ms":665,"lbm_write_time_us":30133,"lbm_writes_lt_1ms":643,"mutex_wait_us":1049,"peak_mem_usage":75542472,"reinsert_count":0,"thread_start_us":71,"threads_started":1,"update_count":3000}
I20260812 06:16:59.428315 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=18.063937
I20260812 06:16:59.492552 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.064s	user 0.028s	sys 0.034s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":24488,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:16:59.493103 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=2.188937
I20260812 06:16:59.508033 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5828,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:59.508517 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling MajorDeltaCompactionOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=1.000000
I20260812 06:16:59.707532 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: MajorDeltaCompactionOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.199s	user 0.135s	sys 0.063s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918098,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":320,"lbm_read_time_us":15204,"lbm_reads_lt_1ms":672,"lbm_write_time_us":29812,"lbm_writes_lt_1ms":643,"mutex_wait_us":234,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6016,"update_count":3000}
I20260812 06:16:59.708410 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=14.095187
I20260812 06:16:59.757624 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.049s	user 0.030s	sys 0.015s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":17641,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:59.758380 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=2.188937
I20260812 06:16:59.771903 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.013s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5037,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:59.772418 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling MajorDeltaCompactionOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=1.000000
I20260812 06:16:59.937614 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: MajorDeltaCompactionOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.165s	user 0.121s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815680,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":563,"lbm_read_time_us":11746,"lbm_reads_lt_1ms":568,"lbm_write_time_us":25319,"lbm_writes_lt_1ms":543,"mutex_wait_us":260,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:16:59.938189 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=14.095187
I20260812 06:16:59.991277 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.053s	user 0.025s	sys 0.022s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":16648,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:59.991837 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=2.188937
I20260812 06:17:00.006682 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.015s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5675,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:00.007151 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling MajorDeltaCompactionOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=1.000000
I20260812 06:17:00.180799 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: MajorDeltaCompactionOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.173s	user 0.104s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1096,"lbm_read_time_us":12443,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26322,"lbm_writes_lt_1ms":543,"mutex_wait_us":477,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:17:00.181335 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=14.095187
I20260812 06:17:00.225761 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.044s	user 0.018s	sys 0.016s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":16737,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:00.226225 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=2.188937
I20260812 06:17:00.244413 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.018s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3630,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:00.244817 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling MajorDeltaCompactionOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=1.000000
I20260812 06:17:00.411455 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: MajorDeltaCompactionOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.166s	user 0.090s	sys 0.069s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":879,"lbm_read_time_us":11086,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25849,"lbm_writes_lt_1ms":543,"mutex_wait_us":280,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6272,"update_count":2500}
I20260812 06:17:00.411988 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=14.095187
I20260812 06:17:00.457240 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.045s	user 0.025s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20244,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:00.457795 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=2.188937
I20260812 06:17:00.470170 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.012s	user 0.005s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4511,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:00.470736 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling MajorDeltaCompactionOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=1.000000
I20260812 06:17:00.639263 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: MajorDeltaCompactionOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.168s	user 0.125s	sys 0.038s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":493,"lbm_read_time_us":11661,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26342,"lbm_writes_lt_1ms":543,"mutex_wait_us":20,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":18304,"update_count":2500}
I20260812 06:17:00.639743 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=14.095187
I20260812 06:17:00.682371 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.042s	user 0.036s	sys 0.004s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":17670,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:00.682888 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=2.188937
I20260812 06:17:00.697628 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5488,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:00.698146 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling FlushMRSOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=1.000000
I20260812 06:17:00.726197 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: FlushMRSOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.028s	user 0.023s	sys 0.004s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":51,"dirs.run_cpu_time_us":213,"dirs.run_wall_time_us":1183,"drs_written":1,"lbm_read_time_us":35,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1661,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:17:00.726787 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling LogGCOp(21a17be99f3e4b38b1657cf2c5686ebc): free 132571329 bytes of WAL
I20260812 06:17:00.726990 22219 log_reader.cc:385] T 21a17be99f3e4b38b1657cf2c5686ebc: removed 13 log segments from log reader
I20260812 06:17:00.727034 22219 log.cc:1079] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/21a17be99f3e4b38b1657cf2c5686ebc/wal-000000015 (ops 71-75)
I20260812 06:17:00.727062 22219 log.cc:1079] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/21a17be99f3e4b38b1657cf2c5686ebc/wal-000000016 (ops 76-80)
I20260812 06:17:00.727095 22219 log.cc:1079] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/21a17be99f3e4b38b1657cf2c5686ebc/wal-000000017 (ops 81-85)
I20260812 06:17:00.727128 22219 log.cc:1079] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/21a17be99f3e4b38b1657cf2c5686ebc/wal-000000018 (ops 86-90)
I20260812 06:17:00.727159 22219 log.cc:1079] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/21a17be99f3e4b38b1657cf2c5686ebc/wal-000000019 (ops 91-94)
I20260812 06:17:00.727191 22219 log.cc:1079] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/21a17be99f3e4b38b1657cf2c5686ebc/wal-000000020 (ops 95-99)
I20260812 06:17:00.727222 22219 log.cc:1079] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/21a17be99f3e4b38b1657cf2c5686ebc/wal-000000021 (ops 100-104)
I20260812 06:17:00.727253 22219 log.cc:1079] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/21a17be99f3e4b38b1657cf2c5686ebc/wal-000000022 (ops 105-108)
I20260812 06:17:00.727283 22219 log.cc:1079] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/21a17be99f3e4b38b1657cf2c5686ebc/wal-000000023 (ops 109-113)
I20260812 06:17:00.727313 22219 log.cc:1079] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/21a17be99f3e4b38b1657cf2c5686ebc/wal-000000024 (ops 114-118)
I20260812 06:17:00.727344 22219 log.cc:1079] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/21a17be99f3e4b38b1657cf2c5686ebc/wal-000000025 (ops 119-123)
I20260812 06:17:00.727373 22219 log.cc:1079] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/21a17be99f3e4b38b1657cf2c5686ebc/wal-000000026 (ops 124-128)
I20260812 06:17:00.727403 22219 log.cc:1079] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/21a17be99f3e4b38b1657cf2c5686ebc/wal-000000027 (ops 129-133)
I20260812 06:17:00.750844 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: LogGCOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.024s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:17:00.751194 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling UndoDeltaBlockGCOp(21a17be99f3e4b38b1657cf2c5686ebc): 492 bytes on disk
I20260812 06:17:00.751579 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: UndoDeltaBlockGCOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4}
I20260812 06:17:00.752061 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=3.181125
I20260812 06:17:00.769831 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.018s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4271,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:00.770213 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=2.188937
I20260812 06:17:00.779484 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3611,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:00.779822 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling MajorDeltaCompactionOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=1.000000
I20260812 06:17:01.014349 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: MajorDeltaCompactionOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.234s	user 0.159s	sys 0.064s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020733,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":975,"lbm_read_time_us":15723,"lbm_reads_lt_1ms":774,"lbm_write_time_us":35115,"lbm_writes_lt_1ms":743,"mutex_wait_us":2,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":2816,"thread_start_us":77,"threads_started":1,"update_count":3500}
I20260812 06:17:01.014916 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=18.063937
I20260812 06:17:01.081002 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.066s	user 0.030s	sys 0.018s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":22963,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:01.081439 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=2.188937
I20260812 06:17:01.091482 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3545,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:01.092084 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling MajorDeltaCompactionOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=1.000000
I20260812 06:17:01.287209 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: MajorDeltaCompactionOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.195s	user 0.125s	sys 0.069s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918098,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":615,"lbm_read_time_us":12775,"lbm_reads_lt_1ms":672,"lbm_write_time_us":34260,"lbm_writes_lt_1ms":643,"mutex_wait_us":27,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12800,"update_count":3000}
I20260812 06:17:01.287798 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=14.095187
I20260812 06:17:01.343434 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.055s	user 0.036s	sys 0.017s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":24781,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:01.344015 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=2.188937
I20260812 06:17:01.353773 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3857,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:01.354274 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling MajorDeltaCompactionOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=1.000000
I20260812 06:17:01.517119 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: MajorDeltaCompactionOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.163s	user 0.112s	sys 0.050s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":210,"lbm_read_time_us":11632,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29896,"lbm_writes_lt_1ms":543,"mutex_wait_us":50,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":2500}
I20260812 06:17:01.517753 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=14.095187
I20260812 06:17:01.569097 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.051s	user 0.027s	sys 0.013s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":17459,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:01.569648 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=2.188937
I20260812 06:17:01.584800 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5769,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:01.585307 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling MajorDeltaCompactionOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=1.000000
I20260812 06:17:01.759284 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: MajorDeltaCompactionOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.174s	user 0.117s	sys 0.055s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":225,"lbm_read_time_us":13008,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29761,"lbm_writes_lt_1ms":543,"mutex_wait_us":18,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:01.759795 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=14.095187
I20260812 06:17:01.818900 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.059s	user 0.033s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19974,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:01.819427 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=2.188937
I20260812 06:17:01.829336 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3800,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:01.829742 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling MajorDeltaCompactionOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=1.000000
I20260812 06:17:02.005326 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: MajorDeltaCompactionOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.175s	user 0.104s	sys 0.059s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":3587,"lbm_read_time_us":11789,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26038,"lbm_writes_lt_1ms":543,"mutex_wait_us":3053,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4480,"update_count":2500}
I20260812 06:17:02.005870 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=14.095187
I20260812 06:17:02.052868 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.047s	user 0.019s	sys 0.025s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":20776,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:02.053370 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=2.188937
I20260812 06:17:02.071645 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.018s	user 0.010s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3643,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:02.072216 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling FlushMRSOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=1.000000
I20260812 06:17:02.105665 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: FlushMRSOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.033s	user 0.021s	sys 0.005s Metrics: {"bytes_written":1152512,"cfile_init":1,"dirs.queue_time_us":58,"dirs.run_cpu_time_us":206,"dirs.run_wall_time_us":1085,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1432,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:02.106408 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling LogGCOp(21a17be99f3e4b38b1657cf2c5686ebc): free 120553584 bytes of WAL
I20260812 06:17:02.106652 22219 log_reader.cc:385] T 21a17be99f3e4b38b1657cf2c5686ebc: removed 12 log segments from log reader
I20260812 06:17:02.106714 22219 log.cc:1079] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/21a17be99f3e4b38b1657cf2c5686ebc/wal-000000028 (ops 134-138)
I20260812 06:17:02.106760 22219 log.cc:1079] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/21a17be99f3e4b38b1657cf2c5686ebc/wal-000000029 (ops 139-142)
I20260812 06:17:02.106789 22219 log.cc:1079] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/21a17be99f3e4b38b1657cf2c5686ebc/wal-000000030 (ops 143-147)
I20260812 06:17:02.106818 22219 log.cc:1079] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/21a17be99f3e4b38b1657cf2c5686ebc/wal-000000031 (ops 148-152)
I20260812 06:17:02.106850 22219 log.cc:1079] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/21a17be99f3e4b38b1657cf2c5686ebc/wal-000000032 (ops 153-156)
I20260812 06:17:02.106881 22219 log.cc:1079] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/21a17be99f3e4b38b1657cf2c5686ebc/wal-000000033 (ops 157-161)
I20260812 06:17:02.106911 22219 log.cc:1079] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/21a17be99f3e4b38b1657cf2c5686ebc/wal-000000034 (ops 162-166)
I20260812 06:17:02.106938 22219 log.cc:1079] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/21a17be99f3e4b38b1657cf2c5686ebc/wal-000000035 (ops 167-171)
I20260812 06:17:02.106966 22219 log.cc:1079] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/21a17be99f3e4b38b1657cf2c5686ebc/wal-000000036 (ops 172-176)
I20260812 06:17:02.106995 22219 log.cc:1079] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/21a17be99f3e4b38b1657cf2c5686ebc/wal-000000037 (ops 177-181)
I20260812 06:17:02.107028 22219 log.cc:1079] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/21a17be99f3e4b38b1657cf2c5686ebc/wal-000000038 (ops 182-186)
I20260812 06:17:02.107055 22219 log.cc:1079] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929: Deleting log segment in path: /tmp/dist-test-taskDVgEcI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515412404881-21636-0/minicluster-data/ts-0-root/wals/21a17be99f3e4b38b1657cf2c5686ebc/wal-000000039 (ops 187-191)
I20260812 06:17:02.131435 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: LogGCOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.025s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:17:02.131805 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=3.181125
I20260812 06:17:02.153271 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.021s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":5009,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:02.153702 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling UndoDeltaBlockGCOp(21a17be99f3e4b38b1657cf2c5686ebc): 447 bytes on disk
I20260812 06:17:02.154172 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: UndoDeltaBlockGCOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4}
I20260812 06:17:02.154678 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=2.188937
I20260812 06:17:02.167886 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4888,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:02.168316 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling MajorDeltaCompactionOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=1.000000
I20260812 06:17:02.345218 21636 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.637s	user 1.652s	sys 0.182s
I20260812 06:17:02.379060 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: MajorDeltaCompactionOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.211s	user 0.159s	sys 0.050s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020732,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":14069,"lbm_reads_lt_1ms":770,"lbm_write_time_us":36914,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":3072,"update_count":3500}
I20260812 06:17:02.379550 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=14.095187
I20260812 06:17:02.410778 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: FlushDeltaMemStoresOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.031s	user 0.005s	sys 0.025s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":14933,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:02.411276 22339 maintenance_manager.cc:419] P 4f9c8096211d402fa46ce1ee5a4ed929: Scheduling MajorDeltaCompactionOp(21a17be99f3e4b38b1657cf2c5686ebc): perf score=1.000000
I20260812 06:17:02.447394 21636 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.102s	user 0.003s	sys 0.000s
I20260812 06:17:02.447970 21636 tablet_server.cc:179] TabletServer@127.21.33.1:0 shutting down...
I20260812 06:17:02.529412 22219 maintenance_manager.cc:643] P 4f9c8096211d402fa46ce1ee5a4ed929: MajorDeltaCompactionOp(21a17be99f3e4b38b1657cf2c5686ebc) complete. Timing: real 0.118s	user 0.099s	sys 0.018s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713155,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":403,"lbm_read_time_us":10009,"lbm_reads_lt_1ms":467,"lbm_write_time_us":22044,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":66,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:02.530059 21636 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:02.530298 21636 tablet_replica.cc:333] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929: stopping tablet replica
I20260812 06:17:02.530457 21636 raft_consensus.cc:2243] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:02.530633 21636 raft_consensus.cc:2272] T 21a17be99f3e4b38b1657cf2c5686ebc P 4f9c8096211d402fa46ce1ee5a4ed929 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:02.544304 21636 tablet_server.cc:196] TabletServer@127.21.33.1:0 shutdown complete.
I20260812 06:17:02.566628 21636 master.cc:562] Master@127.21.33.62:39913 shutting down...
I20260812 06:17:02.569533 21636 raft_consensus.cc:2243] T 00000000000000000000000000000000 P e15eb4d90ee94fab9f66b9a8b26001c8 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:02.569695 21636 raft_consensus.cc:2272] T 00000000000000000000000000000000 P e15eb4d90ee94fab9f66b9a8b26001c8 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:02.569761 21636 tablet_replica.cc:333] T 00000000000000000000000000000000 P e15eb4d90ee94fab9f66b9a8b26001c8: stopping tablet replica
I20260812 06:17:02.581779 21636 master.cc:584] Master@127.21.33.62:39913 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5151 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10238 ms total)

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