[==========] 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:19:43.757380 20789 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.20.77.126:39205
I20260812 06:19:43.758455 20789 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:19:43.759096 20789 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:43.765856 20796 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:19:43.766026 20789 server_base.cc:1061] running on GCE node
W20260812 06:19:43.765867 20799 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:19:43.766239 20797 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:19:43.766814 20789 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:43.766913 20789 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:19:43.766945 20789 hybrid_clock.cc:648] HybridClock initialized: now 1786515583766943 us; error 0 us; skew 500 ppm
I20260812 06:19:43.768878 20789 webserver.cc:533] Webserver started at http://127.20.77.126:42833/ using document root <none> and password file <none>
I20260812 06:19:43.769446 20789 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:43.769505 20789 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:43.769693 20789 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:43.771368 20789 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515583746304-20789-0/minicluster-data/master-0-root/instance:
uuid: "3cf824dbf3214177b51550e59b820426"
format_stamp: "Formatted at 2026-08-12 06:19:43 on dist-test-slave-3h5h"
I20260812 06:19:43.775213 20789 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.005s	sys 0.000s
I20260812 06:19:43.777426 20805 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:19:43.778537 20789 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:19:43.778638 20789 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515583746304-20789-0/minicluster-data/master-0-root
uuid: "3cf824dbf3214177b51550e59b820426"
format_stamp: "Formatted at 2026-08-12 06:19:43 on dist-test-slave-3h5h"
I20260812 06:19:43.778719 20789 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515583746304-20789-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515583746304-20789-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515583746304-20789-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:19:43.797013 20789 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:43.797641 20789 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:19:43.797781 20789 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:43.805573 20789 rpc_server.cc:307] RPC server started. Bound to: 127.20.77.126:39205
I20260812 06:19:43.805588 20909 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.20.77.126:39205 every 8 connection(s)
I20260812 06:19:43.807924 20910 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:19:43.813769 20910 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 3cf824dbf3214177b51550e59b820426: Bootstrap starting.
I20260812 06:19:43.816279 20910 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 3cf824dbf3214177b51550e59b820426: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:43.817359 20910 log.cc:826] T 00000000000000000000000000000000 P 3cf824dbf3214177b51550e59b820426: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:43.819337 20910 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 3cf824dbf3214177b51550e59b820426: No bootstrap required, opened a new log
I20260812 06:19:43.822252 20910 raft_consensus.cc:359] T 00000000000000000000000000000000 P 3cf824dbf3214177b51550e59b820426 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3cf824dbf3214177b51550e59b820426" member_type: VOTER }
I20260812 06:19:43.822424 20910 raft_consensus.cc:385] T 00000000000000000000000000000000 P 3cf824dbf3214177b51550e59b820426 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:43.822500 20910 raft_consensus.cc:740] T 00000000000000000000000000000000 P 3cf824dbf3214177b51550e59b820426 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 3cf824dbf3214177b51550e59b820426, State: Initialized, Role: FOLLOWER
I20260812 06:19:43.823143 20910 consensus_queue.cc:260] T 00000000000000000000000000000000 P 3cf824dbf3214177b51550e59b820426 [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: "3cf824dbf3214177b51550e59b820426" member_type: VOTER }
I20260812 06:19:43.823321 20910 raft_consensus.cc:399] T 00000000000000000000000000000000 P 3cf824dbf3214177b51550e59b820426 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:43.823396 20910 raft_consensus.cc:493] T 00000000000000000000000000000000 P 3cf824dbf3214177b51550e59b820426 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:43.823572 20910 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 3cf824dbf3214177b51550e59b820426 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:43.824429 20910 raft_consensus.cc:515] T 00000000000000000000000000000000 P 3cf824dbf3214177b51550e59b820426 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3cf824dbf3214177b51550e59b820426" member_type: VOTER }
I20260812 06:19:43.824961 20910 leader_election.cc:304] T 00000000000000000000000000000000 P 3cf824dbf3214177b51550e59b820426 [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: 3cf824dbf3214177b51550e59b820426; no voters: 
I20260812 06:19:43.825318 20910 leader_election.cc:290] T 00000000000000000000000000000000 P 3cf824dbf3214177b51550e59b820426 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:43.825536 20915 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 3cf824dbf3214177b51550e59b820426 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:43.825837 20915 raft_consensus.cc:697] T 00000000000000000000000000000000 P 3cf824dbf3214177b51550e59b820426 [term 1 LEADER]: Becoming Leader. State: Replica: 3cf824dbf3214177b51550e59b820426, State: Running, Role: LEADER
I20260812 06:19:43.826365 20915 consensus_queue.cc:237] T 00000000000000000000000000000000 P 3cf824dbf3214177b51550e59b820426 [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: "3cf824dbf3214177b51550e59b820426" member_type: VOTER }
I20260812 06:19:43.826411 20910 sys_catalog.cc:565] T 00000000000000000000000000000000 P 3cf824dbf3214177b51550e59b820426 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:43.828630 20916 sys_catalog.cc:455] T 00000000000000000000000000000000 P 3cf824dbf3214177b51550e59b820426 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "3cf824dbf3214177b51550e59b820426" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3cf824dbf3214177b51550e59b820426" member_type: VOTER } }
I20260812 06:19:43.828769 20916 sys_catalog.cc:458] T 00000000000000000000000000000000 P 3cf824dbf3214177b51550e59b820426 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:43.828776 20789 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:43.828913 20919 sys_catalog.cc:455] T 00000000000000000000000000000000 P 3cf824dbf3214177b51550e59b820426 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 3cf824dbf3214177b51550e59b820426. Latest consensus state: current_term: 1 leader_uuid: "3cf824dbf3214177b51550e59b820426" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3cf824dbf3214177b51550e59b820426" member_type: VOTER } }
I20260812 06:19:43.828992 20919 sys_catalog.cc:458] T 00000000000000000000000000000000 P 3cf824dbf3214177b51550e59b820426 [sys.catalog]: This master's current role is: LEADER
W20260812 06:19:43.831266 20943 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 3cf824dbf3214177b51550e59b820426: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:19:43.831354 20943 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:19:43.831415 20944 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:43.832458 20944 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:43.837847 20944 catalog_manager.cc:1383] Generated new cluster ID: 55831523fbe24ec3866db075b102fe77
I20260812 06:19:43.837945 20944 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:43.857419 20944 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:43.858385 20944 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:43.867456 20944 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 3cf824dbf3214177b51550e59b820426: Generated new TSK 0
I20260812 06:19:43.868204 20944 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:43.894428 20789 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:43.897567 20952 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:19:43.897619 20959 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:19:43.897634 20951 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:19:43.897840 20789 server_base.cc:1061] running on GCE node
I20260812 06:19:43.897991 20789 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:43.898051 20789 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:19:43.898085 20789 hybrid_clock.cc:648] HybridClock initialized: now 1786515583898084 us; error 0 us; skew 500 ppm
I20260812 06:19:43.899058 20789 webserver.cc:533] Webserver started at http://127.20.77.65:35161/ using document root <none> and password file <none>
I20260812 06:19:43.899250 20789 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:43.899323 20789 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:43.899405 20789 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:43.899849 20789 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515583746304-20789-0/minicluster-data/ts-0-root/instance:
uuid: "c7ac7ea5b86b4a0eb93171dc072db80f"
format_stamp: "Formatted at 2026-08-12 06:19:43 on dist-test-slave-3h5h"
I20260812 06:19:43.901481 20789 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:43.902469 20966 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:19:43.902712 20789 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:43.902781 20789 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515583746304-20789-0/minicluster-data/ts-0-root
uuid: "c7ac7ea5b86b4a0eb93171dc072db80f"
format_stamp: "Formatted at 2026-08-12 06:19:43 on dist-test-slave-3h5h"
I20260812 06:19:43.902868 20789 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515583746304-20789-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515583746304-20789-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515583746304-20789-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:19:43.933166 20789 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:43.933624 20789 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:43.934093 20789 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:43.934985 20789 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:43.935060 20789 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:43.935134 20789 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:43.935184 20789 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:43.941799 20789 rpc_server.cc:307] RPC server started. Bound to: 127.20.77.65:44389
I20260812 06:19:43.941864 21089 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.20.77.65:44389 every 8 connection(s)
I20260812 06:19:43.955849 21091 heartbeater.cc:344] Connected to a master server at 127.20.77.126:39205
I20260812 06:19:43.956130 21091 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:43.956586 21091 heartbeater.cc:507] Master 127.20.77.126:39205 requested a full tablet report, sending...
I20260812 06:19:43.958401 20841 ts_manager.cc:194] Registered new tserver with Master: c7ac7ea5b86b4a0eb93171dc072db80f (127.20.77.65:44389)
I20260812 06:19:43.958424 20789 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.015972757s
I20260812 06:19:43.959656 20841 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:56928
I20260812 06:19:43.968730 20841 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:56932:
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:19:43.982928 21027 tablet_service.cc:1511] Processing CreateTablet for tablet 4b55ed8e73ca4c908d1741ac8beac480 (DEFAULT_TABLE table=heavy-update-compaction-test [id=7485dcd199934ba7bba305ffc4188c66]), partition=
I20260812 06:19:43.983439 21027 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 4b55ed8e73ca4c908d1741ac8beac480. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:43.986063 21108 tablet_bootstrap.cc:492] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f: Bootstrap starting.
I20260812 06:19:43.987154 21108 tablet_bootstrap.cc:654] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:43.988273 21108 tablet_bootstrap.cc:492] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f: No bootstrap required, opened a new log
I20260812 06:19:43.988404 21108 ts_tablet_manager.cc:1403] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:43.988884 21108 raft_consensus.cc:359] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c7ac7ea5b86b4a0eb93171dc072db80f" member_type: VOTER last_known_addr { host: "127.20.77.65" port: 44389 } }
I20260812 06:19:43.989015 21108 raft_consensus.cc:385] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:43.989061 21108 raft_consensus.cc:740] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: c7ac7ea5b86b4a0eb93171dc072db80f, State: Initialized, Role: FOLLOWER
I20260812 06:19:43.989219 21108 consensus_queue.cc:260] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f [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: "c7ac7ea5b86b4a0eb93171dc072db80f" member_type: VOTER last_known_addr { host: "127.20.77.65" port: 44389 } }
I20260812 06:19:43.989333 21108 raft_consensus.cc:399] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:43.989391 21108 raft_consensus.cc:493] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:43.989451 21108 raft_consensus.cc:3060] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:43.990253 21108 raft_consensus.cc:515] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c7ac7ea5b86b4a0eb93171dc072db80f" member_type: VOTER last_known_addr { host: "127.20.77.65" port: 44389 } }
I20260812 06:19:43.990411 21108 leader_election.cc:304] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f [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: c7ac7ea5b86b4a0eb93171dc072db80f; no voters: 
I20260812 06:19:43.990655 21108 leader_election.cc:290] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:43.990757 21110 raft_consensus.cc:2804] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:43.990939 21110 raft_consensus.cc:697] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f [term 1 LEADER]: Becoming Leader. State: Replica: c7ac7ea5b86b4a0eb93171dc072db80f, State: Running, Role: LEADER
I20260812 06:19:43.991087 21108 ts_tablet_manager.cc:1434] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:19:43.991173 21110 consensus_queue.cc:237] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f [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: "c7ac7ea5b86b4a0eb93171dc072db80f" member_type: VOTER last_known_addr { host: "127.20.77.65" port: 44389 } }
I20260812 06:19:43.991278 21091 heartbeater.cc:499] Master 127.20.77.126:39205 was elected leader, sending a full tablet report...
I20260812 06:19:43.994374 20841 catalog_manager.cc:5719] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f reported cstate change: term changed from 0 to 1, leader changed from <none> to c7ac7ea5b86b4a0eb93171dc072db80f (127.20.77.65). New cstate: current_term: 1 leader_uuid: "c7ac7ea5b86b4a0eb93171dc072db80f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c7ac7ea5b86b4a0eb93171dc072db80f" member_type: VOTER last_known_addr { host: "127.20.77.65" port: 44389 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:44.054800 20789 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.053s	user 0.019s	sys 0.004s
I20260812 06:19:44.193181 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling FlushMRSOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=15.086190
I20260812 06:19:44.360888 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: FlushMRSOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.167s	user 0.140s	sys 0.024s Metrics: {"bytes_written":13251053,"cfile_init":1,"compiler_manager_pool.queue_time_us":217,"delete_count":0,"dirs.queue_time_us":73,"dirs.run_cpu_time_us":265,"dirs.run_wall_time_us":971,"drs_written":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40251,"lbm_writes_lt_1ms":680,"mutex_wait_us":1209,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"spinlock_wait_cycles":460160,"thread_start_us":142,"threads_started":1,"update_count":1615}
I20260812 06:19:44.362084 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling LogGCOp(4b55ed8e73ca4c908d1741ac8beac480): free 20290830 bytes of WAL
I20260812 06:19:44.362385 20978 log_reader.cc:385] T 4b55ed8e73ca4c908d1741ac8beac480: removed 2 log segments from log reader
I20260812 06:19:44.362442 20978 log.cc:1079] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/4b55ed8e73ca4c908d1741ac8beac480/wal-000000001 (ops 1-6)
I20260812 06:19:44.362500 20978 log.cc:1079] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/4b55ed8e73ca4c908d1741ac8beac480/wal-000000002 (ops 7-10)
I20260812 06:19:44.367645 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: LogGCOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.005s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:19:44.368105 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=4.173312
I20260812 06:19:44.387754 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.019s	user 0.014s	sys 0.004s Metrics: {"bytes_written":6030801,"delete_count":0,"lbm_write_time_us":7994,"lbm_writes_lt_1ms":150,"reinsert_count":0,"update_count":735}
I20260812 06:19:44.388319 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=1.000000
I20260812 06:19:44.394589 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.006s	user 0.001s	sys 0.003s Metrics: {"bytes_written":1230902,"delete_count":0,"lbm_write_time_us":1674,"lbm_writes_lt_1ms":33,"reinsert_count":0,"update_count":150}
I20260812 06:19:44.395108 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling MajorDeltaCompactionOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=1.000000
I20260812 06:19:44.592993 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: MajorDeltaCompactionOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.198s	user 0.144s	sys 0.040s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733786,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":860,"lbm_read_time_us":12347,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31324,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7936,"thread_start_us":372,"threads_started":5,"update_count":2500}
I20260812 06:19:44.593719 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling UndoDeltaBlockGCOp(4b55ed8e73ca4c908d1741ac8beac480): 12308959 bytes on disk
I20260812 06:19:44.594484 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: UndoDeltaBlockGCOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":212,"lbm_reads_lt_1ms":4}
I20260812 06:19:44.595198 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=14.095187
I20260812 06:19:44.649245 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.054s	user 0.036s	sys 0.018s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":23848,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:44.649920 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=2.188937
I20260812 06:19:44.668283 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.018s	user 0.011s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6303,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:44.668958 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling MajorDeltaCompactionOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=1.000000
I20260812 06:19:44.824589 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: MajorDeltaCompactionOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.155s	user 0.129s	sys 0.021s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733722,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":278,"lbm_read_time_us":10813,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31062,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12800,"update_count":2500}
I20260812 06:19:44.825277 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=11.118625
I20260812 06:19:44.865047 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.040s	user 0.032s	sys 0.007s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":16897,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:44.865646 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=2.188937
I20260812 06:19:44.887706 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.022s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4761,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:44.888355 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=2.188937
I20260812 06:19:44.899364 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4083,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:44.900054 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling MajorDeltaCompactionOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=1.000000
I20260812 06:19:45.049533 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: MajorDeltaCompactionOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.149s	user 0.146s	sys 0.003s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733836,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":463,"lbm_read_time_us":10626,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29203,"lbm_writes_lt_1ms":543,"mutex_wait_us":48,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":18432,"update_count":2500}
I20260812 06:19:45.050287 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=10.126437
I20260812 06:19:45.092765 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.042s	user 0.035s	sys 0.004s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":18378,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:45.093458 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=2.188937
I20260812 06:19:45.113897 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.020s	user 0.011s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":8123,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:45.114642 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling MajorDeltaCompactionOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=1.000000
I20260812 06:19:45.239234 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: MajorDeltaCompactionOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.124s	user 0.101s	sys 0.023s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":149,"lbm_read_time_us":9019,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23219,"lbm_writes_lt_1ms":443,"mutex_wait_us":26,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3072,"update_count":2000}
I20260812 06:19:45.239933 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=10.126437
I20260812 06:19:45.286986 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.047s	user 0.019s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17015,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:45.287583 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=2.188937
I20260812 06:19:45.301055 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.013s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4537,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:45.301694 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling MajorDeltaCompactionOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=1.000000
I20260812 06:19:45.444785 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: MajorDeltaCompactionOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.143s	user 0.110s	sys 0.031s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":967,"lbm_read_time_us":8941,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28950,"lbm_writes_lt_1ms":443,"mutex_wait_us":48,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":74880,"update_count":2000}
I20260812 06:19:45.445353 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=10.126437
I20260812 06:19:45.494624 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.049s	user 0.031s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17459,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:45.495491 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=2.188937
I20260812 06:19:45.510659 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.015s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5776,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:45.511289 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling FlushMRSOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=1.000000
I20260812 06:19:45.539984 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: FlushMRSOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.028s	user 0.026s	sys 0.000s Metrics: {"bytes_written":1152509,"cfile_init":1,"dirs.queue_time_us":89,"dirs.run_cpu_time_us":231,"dirs.run_wall_time_us":1546,"drs_written":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1550,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:45.541123 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling LogGCOp(4b55ed8e73ca4c908d1741ac8beac480): free 100674455 bytes of WAL
I20260812 06:19:45.541455 20978 log_reader.cc:385] T 4b55ed8e73ca4c908d1741ac8beac480: removed 10 log segments from log reader
I20260812 06:19:45.541527 20978 log.cc:1079] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/4b55ed8e73ca4c908d1741ac8beac480/wal-000000003 (ops 11-15)
I20260812 06:19:45.541580 20978 log.cc:1079] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/4b55ed8e73ca4c908d1741ac8beac480/wal-000000004 (ops 16-20)
I20260812 06:19:45.541621 20978 log.cc:1079] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/4b55ed8e73ca4c908d1741ac8beac480/wal-000000005 (ops 21-25)
I20260812 06:19:45.541663 20978 log.cc:1079] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/4b55ed8e73ca4c908d1741ac8beac480/wal-000000006 (ops 26-30)
I20260812 06:19:45.541705 20978 log.cc:1079] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/4b55ed8e73ca4c908d1741ac8beac480/wal-000000007 (ops 31-35)
I20260812 06:19:45.541745 20978 log.cc:1079] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/4b55ed8e73ca4c908d1741ac8beac480/wal-000000008 (ops 36-40)
I20260812 06:19:45.541786 20978 log.cc:1079] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/4b55ed8e73ca4c908d1741ac8beac480/wal-000000009 (ops 41-45)
I20260812 06:19:45.541826 20978 log.cc:1079] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/4b55ed8e73ca4c908d1741ac8beac480/wal-000000010 (ops 46-50)
I20260812 06:19:45.541867 20978 log.cc:1079] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/4b55ed8e73ca4c908d1741ac8beac480/wal-000000011 (ops 51-55)
I20260812 06:19:45.541906 20978 log.cc:1079] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/4b55ed8e73ca4c908d1741ac8beac480/wal-000000012 (ops 56-60)
I20260812 06:19:45.564796 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: LogGCOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.023s	user 0.000s	sys 0.020s Metrics: {}
I20260812 06:19:45.565320 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling UndoDeltaBlockGCOp(4b55ed8e73ca4c908d1741ac8beac480): 447 bytes on disk
I20260812 06:19:45.565841 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: UndoDeltaBlockGCOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":79,"lbm_reads_lt_1ms":4}
I20260812 06:19:45.566319 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=3.181125
I20260812 06:19:45.579695 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4652,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:45.580288 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling LogGCOp(4b55ed8e73ca4c908d1741ac8beac480): free 12017927 bytes of WAL
I20260812 06:19:45.580502 20978 log_reader.cc:385] T 4b55ed8e73ca4c908d1741ac8beac480: removed 1 log segments from log reader
I20260812 06:19:45.580544 20978 log.cc:1079] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/4b55ed8e73ca4c908d1741ac8beac480/wal-000000013 (ops 61-65)
I20260812 06:19:45.583431 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: LogGCOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:19:45.583784 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=2.188937
I20260812 06:19:45.595350 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3912,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:45.595832 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling MajorDeltaCompactionOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=1.000000
I20260812 06:19:45.798475 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: MajorDeltaCompactionOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.202s	user 0.130s	sys 0.072s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836361,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":764,"lbm_read_time_us":12948,"lbm_reads_lt_1ms":674,"lbm_write_time_us":32960,"lbm_writes_lt_1ms":643,"mutex_wait_us":329,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1664,"thread_start_us":108,"threads_started":1,"update_count":3000}
I20260812 06:19:45.799052 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=14.095187
I20260812 06:19:45.852365 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.053s	user 0.041s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23481,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2000}
I20260812 06:19:45.853001 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling MajorDeltaCompactionOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=1.000000
I20260812 06:19:46.003217 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: MajorDeltaCompactionOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.150s	user 0.099s	sys 0.049s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20631192,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":162,"lbm_read_time_us":9183,"lbm_reads_lt_1ms":467,"lbm_write_time_us":25243,"lbm_writes_lt_1ms":443,"mutex_wait_us":3,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:19:46.003679 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=11.118625
I20260812 06:19:46.033505 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.030s	user 0.011s	sys 0.018s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":12963,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:46.034102 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=2.188937
I20260812 06:19:46.049197 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.015s	user 0.006s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5363,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:46.049712 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling MajorDeltaCompactionOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=1.000000
I20260812 06:19:46.198937 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: MajorDeltaCompactionOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.149s	user 0.115s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631304,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":411,"lbm_read_time_us":9784,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28785,"lbm_writes_lt_1ms":443,"mutex_wait_us":24,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":23424,"update_count":2000}
I20260812 06:19:46.199532 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=10.126437
I20260812 06:19:46.231392 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.032s	user 0.022s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12969,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:46.232151 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling MajorDeltaCompactionOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=1.000000
I20260812 06:19:46.346784 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: MajorDeltaCompactionOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.114s	user 0.095s	sys 0.019s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16528781,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":330,"lbm_read_time_us":8135,"lbm_reads_lt_1ms":367,"lbm_write_time_us":19573,"lbm_writes_lt_1ms":343,"mutex_wait_us":42,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":1500}
I20260812 06:19:46.347424 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=10.126437
I20260812 06:19:46.384065 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.036s	user 0.017s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15696,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:46.384644 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling MajorDeltaCompactionOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=1.000000
I20260812 06:19:46.504985 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: MajorDeltaCompactionOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.120s	user 0.073s	sys 0.046s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16528781,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":360,"lbm_read_time_us":7176,"lbm_reads_lt_1ms":367,"lbm_write_time_us":21236,"lbm_writes_lt_1ms":343,"mutex_wait_us":23,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":15360,"update_count":1500}
I20260812 06:19:46.505641 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=10.126437
I20260812 06:19:46.543989 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.038s	user 0.011s	sys 0.021s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15522,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:46.544680 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=2.188937
I20260812 06:19:46.557461 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.013s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4555,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:46.557960 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling MajorDeltaCompactionOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=1.000000
I20260812 06:19:46.701232 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: MajorDeltaCompactionOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.143s	user 0.111s	sys 0.031s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":264,"lbm_read_time_us":10575,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28498,"lbm_writes_lt_1ms":443,"mutex_wait_us":58,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:19:46.701896 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=10.126437
I20260812 06:19:46.749375 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.047s	user 0.028s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16312,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:46.749902 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=2.188937
I20260812 06:19:46.762876 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.013s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4632,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:46.763679 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling MajorDeltaCompactionOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=1.000000
I20260812 06:19:46.900594 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: MajorDeltaCompactionOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.137s	user 0.109s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":314,"lbm_read_time_us":11392,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25091,"lbm_writes_lt_1ms":443,"mutex_wait_us":52,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10752,"update_count":2000}
I20260812 06:19:46.901185 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=10.126437
I20260812 06:19:46.947880 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.046s	user 0.020s	sys 0.023s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":16163,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:46.948531 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=2.188937
I20260812 06:19:46.961295 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.013s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4752,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:46.961823 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling MajorDeltaCompactionOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=1.000000
I20260812 06:19:47.127031 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: MajorDeltaCompactionOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.165s	user 0.114s	sys 0.050s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631314,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":2496,"lbm_read_time_us":13036,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27122,"lbm_writes_lt_1ms":443,"mutex_wait_us":561,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2000}
I20260812 06:19:47.127657 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=10.126437
I20260812 06:19:47.162703 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.035s	user 0.020s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15168,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:47.163571 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=2.188937
I20260812 06:19:47.187465 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.024s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6877,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:47.188215 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling FlushMRSOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=1.000000
I20260812 06:19:47.239845 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: FlushMRSOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.051s	user 0.030s	sys 0.001s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":66,"dirs.run_cpu_time_us":179,"dirs.run_wall_time_us":1628,"drs_written":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1746,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:19:47.240661 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling LogGCOp(4b55ed8e73ca4c908d1741ac8beac480): free 121006437 bytes of WAL
I20260812 06:19:47.240990 20978 log_reader.cc:385] T 4b55ed8e73ca4c908d1741ac8beac480: removed 12 log segments from log reader
I20260812 06:19:47.241045 20978 log.cc:1079] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/4b55ed8e73ca4c908d1741ac8beac480/wal-000000014 (ops 66-70)
I20260812 06:19:47.241087 20978 log.cc:1079] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/4b55ed8e73ca4c908d1741ac8beac480/wal-000000015 (ops 71-75)
I20260812 06:19:47.241151 20978 log.cc:1079] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/4b55ed8e73ca4c908d1741ac8beac480/wal-000000016 (ops 76-80)
I20260812 06:19:47.241194 20978 log.cc:1079] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/4b55ed8e73ca4c908d1741ac8beac480/wal-000000017 (ops 81-85)
I20260812 06:19:47.241257 20978 log.cc:1079] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/4b55ed8e73ca4c908d1741ac8beac480/wal-000000018 (ops 86-90)
I20260812 06:19:47.241307 20978 log.cc:1079] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/4b55ed8e73ca4c908d1741ac8beac480/wal-000000019 (ops 91-95)
I20260812 06:19:47.241355 20978 log.cc:1079] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/4b55ed8e73ca4c908d1741ac8beac480/wal-000000020 (ops 96-100)
I20260812 06:19:47.241420 20978 log.cc:1079] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/4b55ed8e73ca4c908d1741ac8beac480/wal-000000021 (ops 101-105)
I20260812 06:19:47.241469 20978 log.cc:1079] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/4b55ed8e73ca4c908d1741ac8beac480/wal-000000022 (ops 106-110)
I20260812 06:19:47.241513 20978 log.cc:1079] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/4b55ed8e73ca4c908d1741ac8beac480/wal-000000023 (ops 111-114)
I20260812 06:19:47.241559 20978 log.cc:1079] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/4b55ed8e73ca4c908d1741ac8beac480/wal-000000024 (ops 115-119)
I20260812 06:19:47.241604 20978 log.cc:1079] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/4b55ed8e73ca4c908d1741ac8beac480/wal-000000025 (ops 120-124)
I20260812 06:19:47.269236 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: LogGCOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.028s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:19:47.269830 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling UndoDeltaBlockGCOp(4b55ed8e73ca4c908d1741ac8beac480): 493 bytes on disk
I20260812 06:19:47.270355 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: UndoDeltaBlockGCOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4}
I20260812 06:19:47.271090 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=7.149875
I20260812 06:19:47.296583 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.025s	user 0.011s	sys 0.012s Metrics: {"bytes_written":8615324,"delete_count":0,"lbm_write_time_us":10895,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:19:47.297282 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling LogGCOp(4b55ed8e73ca4c908d1741ac8beac480): free 12017931 bytes of WAL
I20260812 06:19:47.297626 20978 log_reader.cc:385] T 4b55ed8e73ca4c908d1741ac8beac480: removed 1 log segments from log reader
I20260812 06:19:47.297701 20978 log.cc:1079] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/4b55ed8e73ca4c908d1741ac8beac480/wal-000000026 (ops 125-129)
I20260812 06:19:47.300959 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: LogGCOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.003s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:19:47.301309 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=2.188937
I20260812 06:19:47.316208 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5037,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:47.316774 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling MajorDeltaCompactionOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=1.000000
I20260812 06:19:47.534550 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: MajorDeltaCompactionOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.218s	user 0.133s	sys 0.084s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32938779,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1175,"lbm_read_time_us":15717,"lbm_reads_lt_1ms":766,"lbm_write_time_us":38631,"lbm_writes_lt_1ms":743,"mutex_wait_us":54,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":2560,"thread_start_us":107,"threads_started":1,"update_count":3500}
I20260812 06:19:47.535413 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=14.095187
I20260812 06:19:47.596112 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.061s	user 0.033s	sys 0.016s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":22648,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:47.596665 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=2.188937
I20260812 06:19:47.607767 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4402,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:47.608237 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling MajorDeltaCompactionOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=1.000000
I20260812 06:19:47.771932 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: MajorDeltaCompactionOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.164s	user 0.106s	sys 0.057s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733727,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":317,"lbm_read_time_us":12060,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29206,"lbm_writes_lt_1ms":543,"mutex_wait_us":85,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:19:47.772709 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=11.118625
I20260812 06:19:47.825331 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.052s	user 0.020s	sys 0.031s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":18186,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:47.825899 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=2.188937
I20260812 06:19:47.840777 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.015s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4680,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:47.841459 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=2.188937
I20260812 06:19:47.853820 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.012s	user 0.006s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4652,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:47.854504 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling MajorDeltaCompactionOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=1.000000
I20260812 06:19:48.043052 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: MajorDeltaCompactionOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.188s	user 0.136s	sys 0.045s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733836,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":587,"lbm_read_time_us":12438,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31908,"lbm_writes_lt_1ms":543,"mutex_wait_us":239,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":41600,"update_count":2500}
I20260812 06:19:48.043784 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=14.095187
I20260812 06:19:48.109982 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.066s	user 0.018s	sys 0.047s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25562,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:48.110543 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=2.188937
I20260812 06:19:48.122903 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4846,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:48.123452 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling MajorDeltaCompactionOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=1.000000
I20260812 06:19:48.313232 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: MajorDeltaCompactionOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.190s	user 0.142s	sys 0.047s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":106,"lbm_read_time_us":13645,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33392,"lbm_writes_lt_1ms":543,"mutex_wait_us":62,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2500}
I20260812 06:19:48.314114 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=10.126437
I20260812 06:19:48.354167 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.040s	user 0.030s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17371,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:48.354789 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=2.188937
I20260812 06:19:48.370163 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.015s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5603,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:48.370754 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling MajorDeltaCompactionOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=1.000000
I20260812 06:19:48.524395 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: MajorDeltaCompactionOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.153s	user 0.092s	sys 0.056s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1043,"lbm_read_time_us":8721,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24242,"lbm_writes_lt_1ms":443,"mutex_wait_us":289,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16384,"update_count":2000}
I20260812 06:19:48.525028 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=10.126437
I20260812 06:19:48.563802 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.039s	user 0.028s	sys 0.008s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":17239,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:48.564335 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=2.188937
I20260812 06:19:48.575284 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3998,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:48.575894 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling MajorDeltaCompactionOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=1.000000
I20260812 06:19:48.698551 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: MajorDeltaCompactionOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.122s	user 0.106s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631310,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":210,"lbm_read_time_us":8011,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24115,"lbm_writes_lt_1ms":443,"mutex_wait_us":62,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8064,"update_count":2000}
I20260812 06:19:48.699298 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=10.126437
I20260812 06:19:48.740804 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.041s	user 0.031s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18044,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:48.741466 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=2.188937
I20260812 06:19:48.757863 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.016s	user 0.014s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6129,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:48.758417 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling FlushMRSOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=1.000000
I20260812 06:19:48.797081 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: FlushMRSOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.038s	user 0.024s	sys 0.003s Metrics: {"bytes_written":1234477,"cfile_init":1,"dirs.queue_time_us":77,"dirs.run_cpu_time_us":253,"dirs.run_wall_time_us":1564,"drs_written":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1588,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:48.798007 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling UndoDeltaBlockGCOp(4b55ed8e73ca4c908d1741ac8beac480): 472 bytes on disk
I20260812 06:19:48.798401 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: UndoDeltaBlockGCOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:19:48.798892 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=3.181125
I20260812 06:19:48.810773 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":4549,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:48.811232 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling LogGCOp(4b55ed8e73ca4c908d1741ac8beac480): free 120553586 bytes of WAL
I20260812 06:19:48.811455 20978 log_reader.cc:385] T 4b55ed8e73ca4c908d1741ac8beac480: removed 12 log segments from log reader
I20260812 06:19:48.811499 20978 log.cc:1079] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/4b55ed8e73ca4c908d1741ac8beac480/wal-000000027 (ops 130-134)
I20260812 06:19:48.811528 20978 log.cc:1079] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/4b55ed8e73ca4c908d1741ac8beac480/wal-000000028 (ops 135-139)
I20260812 06:19:48.811591 20978 log.cc:1079] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/4b55ed8e73ca4c908d1741ac8beac480/wal-000000029 (ops 140-144)
I20260812 06:19:48.811645 20978 log.cc:1079] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/4b55ed8e73ca4c908d1741ac8beac480/wal-000000030 (ops 145-149)
I20260812 06:19:48.811707 20978 log.cc:1079] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/4b55ed8e73ca4c908d1741ac8beac480/wal-000000031 (ops 150-154)
I20260812 06:19:48.811757 20978 log.cc:1079] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/4b55ed8e73ca4c908d1741ac8beac480/wal-000000032 (ops 155-158)
I20260812 06:19:48.811792 20978 log.cc:1079] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/4b55ed8e73ca4c908d1741ac8beac480/wal-000000033 (ops 159-163)
I20260812 06:19:48.811830 20978 log.cc:1079] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/4b55ed8e73ca4c908d1741ac8beac480/wal-000000034 (ops 164-168)
I20260812 06:19:48.811868 20978 log.cc:1079] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/4b55ed8e73ca4c908d1741ac8beac480/wal-000000035 (ops 169-172)
I20260812 06:19:48.811909 20978 log.cc:1079] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/4b55ed8e73ca4c908d1741ac8beac480/wal-000000036 (ops 173-177)
I20260812 06:19:48.811947 20978 log.cc:1079] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/4b55ed8e73ca4c908d1741ac8beac480/wal-000000037 (ops 178-182)
I20260812 06:19:48.811985 20978 log.cc:1079] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/4b55ed8e73ca4c908d1741ac8beac480/wal-000000038 (ops 183-187)
I20260812 06:19:48.838732 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: LogGCOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.027s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:19:48.839186 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=2.188937
I20260812 06:19:48.854771 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.015s	user 0.004s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4182,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:48.855319 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=2.188937
I20260812 06:19:48.865924 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4014,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:48.866500 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling MajorDeltaCompactionOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=1.000000
I20260812 06:19:49.065138 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: MajorDeltaCompactionOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.198s	user 0.155s	sys 0.043s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32938891,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":812,"lbm_read_time_us":13218,"lbm_reads_lt_1ms":775,"lbm_write_time_us":40768,"lbm_writes_lt_1ms":743,"mutex_wait_us":292,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1536,"thread_start_us":147,"threads_started":1,"update_count":3500}
I20260812 06:19:49.066077 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=14.095187
I20260812 06:19:49.107529 20789 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.053s	user 1.864s	sys 0.137s
I20260812 06:19:49.113215 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.047s	user 0.025s	sys 0.021s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22214,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:49.114329 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=2.188937
I20260812 06:19:49.134629 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: FlushDeltaMemStoresOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.020s	user 0.016s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7987,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:49.135442 21092 maintenance_manager.cc:419] P c7ac7ea5b86b4a0eb93171dc072db80f: Scheduling MajorDeltaCompactionOp(4b55ed8e73ca4c908d1741ac8beac480): perf score=1.000000
I20260812 06:19:49.168495 20789 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.060s	user 0.003s	sys 0.000s
I20260812 06:19:49.169368 20789 tablet_server.cc:179] TabletServer@127.20.77.65:0 shutting down...
I20260812 06:19:49.298835 20978 maintenance_manager.cc:643] P c7ac7ea5b86b4a0eb93171dc072db80f: MajorDeltaCompactionOp(4b55ed8e73ca4c908d1741ac8beac480) complete. Timing: real 0.163s	user 0.125s	sys 0.036s Metrics: {"cfile_cache_hit":29,"cfile_cache_hit_bytes":3959166,"cfile_cache_miss":503,"cfile_cache_miss_bytes":20774558,"cfile_init":4,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":342,"lbm_read_time_us":15063,"lbm_reads_lt_1ms":519,"lbm_write_time_us":31866,"lbm_writes_lt_1ms":543,"mutex_wait_us":133,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:49.299953 20789 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:49.300496 20789 tablet_replica.cc:333] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f: stopping tablet replica
I20260812 06:19:49.300771 20789 raft_consensus.cc:2243] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:49.301055 20789 raft_consensus.cc:2272] T 4b55ed8e73ca4c908d1741ac8beac480 P c7ac7ea5b86b4a0eb93171dc072db80f [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:49.308323 20789 tablet_server.cc:196] TabletServer@127.20.77.65:0 shutdown complete.
I20260812 06:19:49.345417 20789 master.cc:562] Master@127.20.77.126:39205 shutting down...
I20260812 06:19:49.349525 20789 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 3cf824dbf3214177b51550e59b820426 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:49.349737 20789 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 3cf824dbf3214177b51550e59b820426 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:49.349844 20789 tablet_replica.cc:333] T 00000000000000000000000000000000 P 3cf824dbf3214177b51550e59b820426: stopping tablet replica
I20260812 06:19:49.362411 20789 master.cc:584] Master@127.20.77.126:39205 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5696 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:49.464730 20789 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.20.77.126:40575
I20260812 06:19:49.465245 20789 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:49.467392 21142 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:19:49.467394 21141 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:19:49.467507 21148 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:19:49.467523 20789 server_base.cc:1061] running on GCE node
I20260812 06:19:49.467852 20789 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:49.467897 20789 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:19:49.467913 20789 hybrid_clock.cc:648] HybridClock initialized: now 1786515589467913 us; error 0 us; skew 500 ppm
I20260812 06:19:49.468819 20789 webserver.cc:533] Webserver started at http://127.20.77.126:33377/ using document root <none> and password file <none>
I20260812 06:19:49.469076 20789 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:49.469192 20789 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:49.469297 20789 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:49.469713 20789 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515583746304-20789-0/minicluster-data/master-0-root/instance:
uuid: "e6c4598b34024f09aaa60f65c823daac"
format_stamp: "Formatted at 2026-08-12 06:19:49 on dist-test-slave-3h5h"
I20260812 06:19:49.471314 20789 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:19:49.472422 21154 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:19:49.472698 20789 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:49.472795 20789 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515583746304-20789-0/minicluster-data/master-0-root
uuid: "e6c4598b34024f09aaa60f65c823daac"
format_stamp: "Formatted at 2026-08-12 06:19:49 on dist-test-slave-3h5h"
I20260812 06:19:49.472911 20789 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515583746304-20789-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515583746304-20789-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515583746304-20789-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:19:49.500540 20789 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:49.501060 20789 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:49.505545 20789 rpc_server.cc:307] RPC server started. Bound to: 127.20.77.126:40575
I20260812 06:19:49.506925 21235 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.20.77.126:40575 every 8 connection(s)
I20260812 06:19:49.508695 21237 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:19:49.510690 21237 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P e6c4598b34024f09aaa60f65c823daac: Bootstrap starting.
I20260812 06:19:49.511493 21237 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P e6c4598b34024f09aaa60f65c823daac: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:49.512537 21237 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P e6c4598b34024f09aaa60f65c823daac: No bootstrap required, opened a new log
I20260812 06:19:49.513131 21237 raft_consensus.cc:359] T 00000000000000000000000000000000 P e6c4598b34024f09aaa60f65c823daac [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e6c4598b34024f09aaa60f65c823daac" member_type: VOTER }
I20260812 06:19:49.513227 21237 raft_consensus.cc:385] T 00000000000000000000000000000000 P e6c4598b34024f09aaa60f65c823daac [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:49.513274 21237 raft_consensus.cc:740] T 00000000000000000000000000000000 P e6c4598b34024f09aaa60f65c823daac [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: e6c4598b34024f09aaa60f65c823daac, State: Initialized, Role: FOLLOWER
I20260812 06:19:49.513468 21237 consensus_queue.cc:260] T 00000000000000000000000000000000 P e6c4598b34024f09aaa60f65c823daac [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: "e6c4598b34024f09aaa60f65c823daac" member_type: VOTER }
I20260812 06:19:49.513569 21237 raft_consensus.cc:399] T 00000000000000000000000000000000 P e6c4598b34024f09aaa60f65c823daac [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:49.513595 21237 raft_consensus.cc:493] T 00000000000000000000000000000000 P e6c4598b34024f09aaa60f65c823daac [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:49.513646 21237 raft_consensus.cc:3060] T 00000000000000000000000000000000 P e6c4598b34024f09aaa60f65c823daac [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:49.514437 21237 raft_consensus.cc:515] T 00000000000000000000000000000000 P e6c4598b34024f09aaa60f65c823daac [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e6c4598b34024f09aaa60f65c823daac" member_type: VOTER }
I20260812 06:19:49.514591 21237 leader_election.cc:304] T 00000000000000000000000000000000 P e6c4598b34024f09aaa60f65c823daac [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: e6c4598b34024f09aaa60f65c823daac; no voters: 
I20260812 06:19:49.514833 21237 leader_election.cc:290] T 00000000000000000000000000000000 P e6c4598b34024f09aaa60f65c823daac [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:49.514977 21242 raft_consensus.cc:2804] T 00000000000000000000000000000000 P e6c4598b34024f09aaa60f65c823daac [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:49.515194 21242 raft_consensus.cc:697] T 00000000000000000000000000000000 P e6c4598b34024f09aaa60f65c823daac [term 1 LEADER]: Becoming Leader. State: Replica: e6c4598b34024f09aaa60f65c823daac, State: Running, Role: LEADER
I20260812 06:19:49.515340 21242 consensus_queue.cc:237] T 00000000000000000000000000000000 P e6c4598b34024f09aaa60f65c823daac [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: "e6c4598b34024f09aaa60f65c823daac" member_type: VOTER }
I20260812 06:19:49.515349 21237 sys_catalog.cc:565] T 00000000000000000000000000000000 P e6c4598b34024f09aaa60f65c823daac [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:49.515848 21243 sys_catalog.cc:455] T 00000000000000000000000000000000 P e6c4598b34024f09aaa60f65c823daac [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "e6c4598b34024f09aaa60f65c823daac" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e6c4598b34024f09aaa60f65c823daac" member_type: VOTER } }
I20260812 06:19:49.515897 21244 sys_catalog.cc:455] T 00000000000000000000000000000000 P e6c4598b34024f09aaa60f65c823daac [sys.catalog]: SysCatalogTable state changed. Reason: New leader e6c4598b34024f09aaa60f65c823daac. Latest consensus state: current_term: 1 leader_uuid: "e6c4598b34024f09aaa60f65c823daac" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e6c4598b34024f09aaa60f65c823daac" member_type: VOTER } }
I20260812 06:19:49.516008 21243 sys_catalog.cc:458] T 00000000000000000000000000000000 P e6c4598b34024f09aaa60f65c823daac [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:49.516086 21244 sys_catalog.cc:458] T 00000000000000000000000000000000 P e6c4598b34024f09aaa60f65c823daac [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:49.516680 21249 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:49.517530 21249 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:49.517735 20789 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:49.519418 21249 catalog_manager.cc:1383] Generated new cluster ID: 250c6e6ea662435db40bfb61fec7ed87
I20260812 06:19:49.519481 21249 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:49.545202 21249 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:49.545835 21249 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:49.551168 21249 catalog_manager.cc:6092] T 00000000000000000000000000000000 P e6c4598b34024f09aaa60f65c823daac: Generated new TSK 0
I20260812 06:19:49.551368 21249 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:49.582552 20789 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:49.584905 21282 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:19:49.585054 20789 server_base.cc:1061] running on GCE node
W20260812 06:19:49.584995 21276 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:19:49.585021 21277 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:19:49.585436 20789 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:49.585489 20789 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:19:49.585506 20789 hybrid_clock.cc:648] HybridClock initialized: now 1786515589585506 us; error 0 us; skew 500 ppm
I20260812 06:19:49.586450 20789 webserver.cc:533] Webserver started at http://127.20.77.65:41909/ using document root <none> and password file <none>
I20260812 06:19:49.586622 20789 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:49.586674 20789 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:49.586732 20789 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:49.587126 20789 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515583746304-20789-0/minicluster-data/ts-0-root/instance:
uuid: "7138e5b3a6d44a35b7be31fc932862bc"
format_stamp: "Formatted at 2026-08-12 06:19:49 on dist-test-slave-3h5h"
I20260812 06:19:49.588703 20789 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:49.589967 21290 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:19:49.590283 20789 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:49.590353 20789 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515583746304-20789-0/minicluster-data/ts-0-root
uuid: "7138e5b3a6d44a35b7be31fc932862bc"
format_stamp: "Formatted at 2026-08-12 06:19:49 on dist-test-slave-3h5h"
I20260812 06:19:49.590413 20789 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515583746304-20789-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515583746304-20789-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515583746304-20789-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:19:49.627148 20789 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:49.627554 20789 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:49.627856 20789 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:49.628423 20789 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:49.628464 20789 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:49.628539 20789 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:49.628582 20789 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:49.633590 20789 rpc_server.cc:307] RPC server started. Bound to: 127.20.77.65:43181
I20260812 06:19:49.635147 21391 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.20.77.65:43181 every 8 connection(s)
I20260812 06:19:49.640321 21392 heartbeater.cc:344] Connected to a master server at 127.20.77.126:40575
I20260812 06:19:49.640435 21392 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:49.640715 21392 heartbeater.cc:507] Master 127.20.77.126:40575 requested a full tablet report, sending...
I20260812 06:19:49.641459 21176 ts_manager.cc:194] Registered new tserver with Master: 7138e5b3a6d44a35b7be31fc932862bc (127.20.77.65:43181)
I20260812 06:19:49.642204 21176 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:37904
I20260812 06:19:49.642511 20789 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.007959691s
I20260812 06:19:49.650238 21176 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:37916:
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:19:49.660879 21334 tablet_service.cc:1511] Processing CreateTablet for tablet 81415504b90b418f96e8487b7b562bcb (DEFAULT_TABLE table=heavy-update-compaction-test [id=f4f501b4e64740458df7a0187db4f213]), partition=
I20260812 06:19:49.661176 21334 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 81415504b90b418f96e8487b7b562bcb. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:49.663424 21419 tablet_bootstrap.cc:492] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc: Bootstrap starting.
I20260812 06:19:49.664395 21419 tablet_bootstrap.cc:654] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:49.665659 21419 tablet_bootstrap.cc:492] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc: No bootstrap required, opened a new log
I20260812 06:19:49.665776 21419 ts_tablet_manager.cc:1403] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:49.666378 21419 raft_consensus.cc:359] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7138e5b3a6d44a35b7be31fc932862bc" member_type: VOTER last_known_addr { host: "127.20.77.65" port: 43181 } }
I20260812 06:19:49.666468 21419 raft_consensus.cc:385] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:49.666491 21419 raft_consensus.cc:740] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 7138e5b3a6d44a35b7be31fc932862bc, State: Initialized, Role: FOLLOWER
I20260812 06:19:49.666625 21419 consensus_queue.cc:260] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc [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: "7138e5b3a6d44a35b7be31fc932862bc" member_type: VOTER last_known_addr { host: "127.20.77.65" port: 43181 } }
I20260812 06:19:49.666714 21419 raft_consensus.cc:399] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:49.666739 21419 raft_consensus.cc:493] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:49.666775 21419 raft_consensus.cc:3060] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:49.667451 21419 raft_consensus.cc:515] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7138e5b3a6d44a35b7be31fc932862bc" member_type: VOTER last_known_addr { host: "127.20.77.65" port: 43181 } }
I20260812 06:19:49.667570 21419 leader_election.cc:304] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc [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: 7138e5b3a6d44a35b7be31fc932862bc; no voters: 
I20260812 06:19:49.667730 21419 leader_election.cc:290] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:49.667872 21421 raft_consensus.cc:2804] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:49.668083 21392 heartbeater.cc:499] Master 127.20.77.126:40575 was elected leader, sending a full tablet report...
I20260812 06:19:49.668154 21421 raft_consensus.cc:697] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc [term 1 LEADER]: Becoming Leader. State: Replica: 7138e5b3a6d44a35b7be31fc932862bc, State: Running, Role: LEADER
I20260812 06:19:49.668313 21421 consensus_queue.cc:237] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc [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: "7138e5b3a6d44a35b7be31fc932862bc" member_type: VOTER last_known_addr { host: "127.20.77.65" port: 43181 } }
I20260812 06:19:49.668082 21419 ts_tablet_manager.cc:1434] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:19:49.669709 21176 catalog_manager.cc:5719] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc reported cstate change: term changed from 0 to 1, leader changed from <none> to 7138e5b3a6d44a35b7be31fc932862bc (127.20.77.65). New cstate: current_term: 1 leader_uuid: "7138e5b3a6d44a35b7be31fc932862bc" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7138e5b3a6d44a35b7be31fc932862bc" member_type: VOTER last_known_addr { host: "127.20.77.65" port: 43181 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:49.729568 20789 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.053s	user 0.014s	sys 0.009s
I20260812 06:19:49.885715 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling FlushMRSOp(81415504b90b418f96e8487b7b562bcb): perf score=19.054940
I20260812 06:19:50.059196 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: FlushMRSOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.173s	user 0.125s	sys 0.044s Metrics: {"bytes_written":12307491,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":69,"dirs.run_cpu_time_us":196,"dirs.run_wall_time_us":1088,"drs_written":1,"lbm_read_time_us":114,"lbm_reads_lt_1ms":4,"lbm_write_time_us":44194,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":3840,"update_count":1500}
I20260812 06:19:50.059900 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling LogGCOp(81415504b90b418f96e8487b7b562bcb): free 20743880 bytes of WAL
I20260812 06:19:50.060158 21300 log_reader.cc:385] T 81415504b90b418f96e8487b7b562bcb: removed 2 log segments from log reader
I20260812 06:19:50.060210 21300 log.cc:1079] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/81415504b90b418f96e8487b7b562bcb/wal-000000001 (ops 1-6)
I20260812 06:19:50.060241 21300 log.cc:1079] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/81415504b90b418f96e8487b7b562bcb/wal-000000002 (ops 7-11)
I20260812 06:19:50.065918 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: LogGCOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.006s	user 0.000s	sys 0.005s Metrics: {}
I20260812 06:19:50.066350 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling UndoDeltaBlockGCOp(81415504b90b418f96e8487b7b562bcb): 16411394 bytes on disk
I20260812 06:19:50.066931 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: UndoDeltaBlockGCOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":117,"lbm_reads_lt_1ms":4}
I20260812 06:19:50.067430 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb): perf score=3.181125
I20260812 06:19:50.085232 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.018s	user 0.004s	sys 0.009s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4913,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:50.085675 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb): perf score=2.188937
I20260812 06:19:50.095496 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3689,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:50.095916 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling MajorDeltaCompactionOp(81415504b90b418f96e8487b7b562bcb): perf score=1.000000
I20260812 06:19:50.276117 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: MajorDeltaCompactionOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.180s	user 0.117s	sys 0.061s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774796,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":815,"lbm_read_time_us":12377,"lbm_reads_lt_1ms":569,"lbm_write_time_us":29536,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4864,"thread_start_us":334,"threads_started":5,"update_count":2500}
I20260812 06:19:50.276669 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb): perf score=14.095187
I20260812 06:19:50.337329 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.060s	user 0.030s	sys 0.019s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":18194,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:50.337877 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb): perf score=2.188937
I20260812 06:19:50.348608 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4217,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:50.349087 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling MajorDeltaCompactionOp(81415504b90b418f96e8487b7b562bcb): perf score=1.000000
I20260812 06:19:50.542661 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: MajorDeltaCompactionOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.193s	user 0.129s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":977,"lbm_read_time_us":13118,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29907,"lbm_writes_lt_1ms":543,"mutex_wait_us":384,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10752,"update_count":2500}
I20260812 06:19:50.543278 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb): perf score=14.095187
I20260812 06:19:50.613297 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.070s	user 0.031s	sys 0.035s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25426,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:50.613863 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb): perf score=2.188937
I20260812 06:19:50.625847 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.012s	user 0.005s	sys 0.006s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4612,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:50.626379 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling MajorDeltaCompactionOp(81415504b90b418f96e8487b7b562bcb): perf score=1.000000
I20260812 06:19:50.827092 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: MajorDeltaCompactionOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.201s	user 0.121s	sys 0.069s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":975,"lbm_read_time_us":13183,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32550,"lbm_writes_lt_1ms":543,"mutex_wait_us":268,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14848,"update_count":2500}
I20260812 06:19:50.827785 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb): perf score=14.095187
I20260812 06:19:50.876541 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.049s	user 0.016s	sys 0.027s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20468,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:50.877174 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb): perf score=2.188937
I20260812 06:19:50.898368 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.021s	user 0.008s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4454,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:50.898921 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling MajorDeltaCompactionOp(81415504b90b418f96e8487b7b562bcb): perf score=1.000000
I20260812 06:19:51.083369 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: MajorDeltaCompactionOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.184s	user 0.109s	sys 0.075s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":748,"lbm_read_time_us":12928,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32718,"lbm_writes_lt_1ms":543,"mutex_wait_us":53,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5888,"update_count":2500}
I20260812 06:19:51.084136 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb): perf score=14.095187
I20260812 06:19:51.133236 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.049s	user 0.025s	sys 0.024s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":21643,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:51.133817 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb): perf score=2.188937
I20260812 06:19:51.146624 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4975,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:51.147120 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling MajorDeltaCompactionOp(81415504b90b418f96e8487b7b562bcb): perf score=1.000000
I20260812 06:19:51.324800 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: MajorDeltaCompactionOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.177s	user 0.108s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":290,"lbm_read_time_us":11118,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27598,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12032,"update_count":2500}
I20260812 06:19:51.325373 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb): perf score=14.095187
I20260812 06:19:51.385058 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.059s	user 0.032s	sys 0.027s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":26973,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:51.385694 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb): perf score=2.188937
I20260812 06:19:51.399616 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.014s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5205,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:51.400170 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling FlushMRSOp(81415504b90b418f96e8487b7b562bcb): perf score=1.000000
I20260812 06:19:51.431144 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: FlushMRSOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.031s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":84,"dirs.run_cpu_time_us":298,"dirs.run_wall_time_us":1719,"drs_written":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1570,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31,"spinlock_wait_cycles":17280}
I20260812 06:19:51.431736 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling LogGCOp(81415504b90b418f96e8487b7b562bcb): free 124257239 bytes of WAL
I20260812 06:19:51.431973 21300 log_reader.cc:385] T 81415504b90b418f96e8487b7b562bcb: removed 12 log segments from log reader
I20260812 06:19:51.432016 21300 log.cc:1079] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/81415504b90b418f96e8487b7b562bcb/wal-000000003 (ops 12-16)
I20260812 06:19:51.432045 21300 log.cc:1079] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/81415504b90b418f96e8487b7b562bcb/wal-000000004 (ops 17-21)
I20260812 06:19:51.432063 21300 log.cc:1079] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/81415504b90b418f96e8487b7b562bcb/wal-000000005 (ops 22-26)
I20260812 06:19:51.432132 21300 log.cc:1079] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/81415504b90b418f96e8487b7b562bcb/wal-000000006 (ops 27-31)
I20260812 06:19:51.432197 21300 log.cc:1079] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/81415504b90b418f96e8487b7b562bcb/wal-000000007 (ops 32-36)
I20260812 06:19:51.432250 21300 log.cc:1079] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/81415504b90b418f96e8487b7b562bcb/wal-000000008 (ops 37-41)
I20260812 06:19:51.432284 21300 log.cc:1079] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/81415504b90b418f96e8487b7b562bcb/wal-000000009 (ops 42-46)
I20260812 06:19:51.432344 21300 log.cc:1079] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/81415504b90b418f96e8487b7b562bcb/wal-000000010 (ops 47-51)
I20260812 06:19:51.432379 21300 log.cc:1079] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/81415504b90b418f96e8487b7b562bcb/wal-000000011 (ops 52-56)
I20260812 06:19:51.432420 21300 log.cc:1079] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/81415504b90b418f96e8487b7b562bcb/wal-000000012 (ops 57-60)
I20260812 06:19:51.432459 21300 log.cc:1079] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/81415504b90b418f96e8487b7b562bcb/wal-000000013 (ops 61-65)
I20260812 06:19:51.432494 21300 log.cc:1079] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/81415504b90b418f96e8487b7b562bcb/wal-000000014 (ops 66-70)
I20260812 06:19:51.457058 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: LogGCOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.025s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:19:51.457580 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb): perf score=5.165500
I20260812 06:19:51.480168 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.022s	user 0.011s	sys 0.009s Metrics: {"bytes_written":6646162,"delete_count":0,"lbm_write_time_us":9553,"lbm_writes_lt_1ms":165,"reinsert_count":0,"update_count":810}
I20260812 06:19:51.480722 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling UndoDeltaBlockGCOp(81415504b90b418f96e8487b7b562bcb): 483 bytes on disk
I20260812 06:19:51.481257 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: UndoDeltaBlockGCOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4}
I20260812 06:19:51.481772 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb): perf score=1.000000
I20260812 06:19:51.490756 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.009s	user 0.006s	sys 0.001s Metrics: {"bytes_written":1559102,"delete_count":0,"lbm_write_time_us":2693,"lbm_writes_lt_1ms":41,"reinsert_count":0,"update_count":190}
I20260812 06:19:51.491364 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling MajorDeltaCompactionOp(81415504b90b418f96e8487b7b562bcb): perf score=1.000000
I20260812 06:19:51.728120 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: MajorDeltaCompactionOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.237s	user 0.122s	sys 0.109s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1030,"lbm_read_time_us":15726,"lbm_reads_lt_1ms":774,"lbm_write_time_us":39112,"lbm_writes_lt_1ms":743,"mutex_wait_us":349,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":3456,"thread_start_us":114,"threads_started":1,"update_count":3500}
I20260812 06:19:51.729854 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb): perf score=16.079562
I20260812 06:19:51.785833 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.056s	user 0.028s	sys 0.025s Metrics: {"bytes_written":17681653,"delete_count":0,"lbm_write_time_us":24436,"lbm_writes_lt_1ms":434,"reinsert_count":0,"update_count":2155}
I20260812 06:19:51.786417 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb): perf score=2.188937
I20260812 06:19:51.810115 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.023s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3241134,"delete_count":0,"lbm_write_time_us":4631,"lbm_writes_lt_1ms":82,"reinsert_count":0,"update_count":395}
I20260812 06:19:51.810621 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb): perf score=2.188937
I20260812 06:19:51.820488 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.010s	user 0.005s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3649,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:51.821012 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling MajorDeltaCompactionOp(81415504b90b418f96e8487b7b562bcb): perf score=1.000000
I20260812 06:19:52.028303 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: MajorDeltaCompactionOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.207s	user 0.140s	sys 0.064s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877192,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":807,"lbm_read_time_us":13809,"lbm_reads_lt_1ms":673,"lbm_write_time_us":33920,"lbm_writes_lt_1ms":643,"mutex_wait_us":377,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":3000}
I20260812 06:19:52.029145 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb): perf score=17.071750
I20260812 06:19:52.090781 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.061s	user 0.032s	sys 0.025s Metrics: {"bytes_written":18789300,"delete_count":0,"lbm_write_time_us":27076,"lbm_writes_lt_1ms":461,"reinsert_count":0,"update_count":2290}
I20260812 06:19:52.091363 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb): perf score=1.000000
I20260812 06:19:52.102154 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.011s	user 0.001s	sys 0.004s Metrics: {"bytes_written":2133458,"delete_count":0,"lbm_write_time_us":2262,"lbm_writes_lt_1ms":55,"reinsert_count":0,"update_count":260}
I20260812 06:19:52.102631 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb): perf score=2.188937
I20260812 06:19:52.112469 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.010s	user 0.001s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3722,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:52.113030 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling MajorDeltaCompactionOp(81415504b90b418f96e8487b7b562bcb): perf score=1.000000
I20260812 06:19:52.340649 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: MajorDeltaCompactionOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.227s	user 0.125s	sys 0.093s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877163,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":450,"lbm_read_time_us":14921,"lbm_reads_lt_1ms":673,"lbm_write_time_us":37409,"lbm_writes_lt_1ms":643,"mutex_wait_us":24,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":22912,"update_count":3000}
I20260812 06:19:52.341375 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb): perf score=18.063937
I20260812 06:19:52.420344 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.079s	user 0.035s	sys 0.039s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":34918,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":501,"reinsert_count":0,"update_count":2500}
I20260812 06:19:52.420975 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb): perf score=2.188937
I20260812 06:19:52.437826 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.017s	user 0.011s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6562,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:52.438447 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling MajorDeltaCompactionOp(81415504b90b418f96e8487b7b562bcb): perf score=1.000000
I20260812 06:19:52.636986 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: MajorDeltaCompactionOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.198s	user 0.121s	sys 0.075s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1278,"lbm_read_time_us":13861,"lbm_reads_lt_1ms":672,"lbm_write_time_us":35360,"lbm_writes_lt_1ms":643,"mutex_wait_us":62,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4096,"update_count":3000}
I20260812 06:19:52.637571 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb): perf score=14.095187
I20260812 06:19:52.696180 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.058s	user 0.008s	sys 0.036s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21086,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:52.696708 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb): perf score=2.188937
I20260812 06:19:52.707460 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4199,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:52.708148 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling MajorDeltaCompactionOp(81415504b90b418f96e8487b7b562bcb): perf score=1.000000
I20260812 06:19:52.890141 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: MajorDeltaCompactionOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.182s	user 0.129s	sys 0.043s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":675,"lbm_read_time_us":11515,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29135,"lbm_writes_lt_1ms":543,"mutex_wait_us":109,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:19:52.890899 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb): perf score=14.095187
I20260812 06:19:52.956267 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.065s	user 0.037s	sys 0.016s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23287,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:52.956943 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb): perf score=2.188937
I20260812 06:19:52.970738 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.014s	user 0.002s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5007,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:52.973277 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling FlushMRSOp(81415504b90b418f96e8487b7b562bcb): perf score=1.000000
I20260812 06:19:53.002560 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: FlushMRSOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.029s	user 0.020s	sys 0.004s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":76,"dirs.run_cpu_time_us":276,"dirs.run_wall_time_us":1841,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1485,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:53.003419 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling LogGCOp(81415504b90b418f96e8487b7b562bcb): free 120553406 bytes of WAL
I20260812 06:19:53.003695 21300 log_reader.cc:385] T 81415504b90b418f96e8487b7b562bcb: removed 12 log segments from log reader
I20260812 06:19:53.003769 21300 log.cc:1079] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/81415504b90b418f96e8487b7b562bcb/wal-000000015 (ops 71-75)
I20260812 06:19:53.003820 21300 log.cc:1079] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/81415504b90b418f96e8487b7b562bcb/wal-000000016 (ops 76-80)
I20260812 06:19:53.003878 21300 log.cc:1079] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/81415504b90b418f96e8487b7b562bcb/wal-000000017 (ops 81-85)
I20260812 06:19:53.003922 21300 log.cc:1079] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/81415504b90b418f96e8487b7b562bcb/wal-000000018 (ops 86-90)
I20260812 06:19:53.003959 21300 log.cc:1079] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/81415504b90b418f96e8487b7b562bcb/wal-000000019 (ops 91-95)
I20260812 06:19:53.004000 21300 log.cc:1079] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/81415504b90b418f96e8487b7b562bcb/wal-000000020 (ops 96-100)
I20260812 06:19:53.004038 21300 log.cc:1079] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/81415504b90b418f96e8487b7b562bcb/wal-000000021 (ops 101-105)
I20260812 06:19:53.004077 21300 log.cc:1079] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/81415504b90b418f96e8487b7b562bcb/wal-000000022 (ops 106-110)
I20260812 06:19:53.004117 21300 log.cc:1079] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/81415504b90b418f96e8487b7b562bcb/wal-000000023 (ops 111-114)
I20260812 06:19:53.004158 21300 log.cc:1079] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/81415504b90b418f96e8487b7b562bcb/wal-000000024 (ops 115-119)
I20260812 06:19:53.004197 21300 log.cc:1079] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/81415504b90b418f96e8487b7b562bcb/wal-000000025 (ops 120-124)
I20260812 06:19:53.004237 21300 log.cc:1079] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/81415504b90b418f96e8487b7b562bcb/wal-000000026 (ops 125-128)
I20260812 06:19:53.029389 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: LogGCOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.026s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:19:53.029923 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling UndoDeltaBlockGCOp(81415504b90b418f96e8487b7b562bcb): 462 bytes on disk
I20260812 06:19:53.030562 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: UndoDeltaBlockGCOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":76,"lbm_reads_lt_1ms":4}
I20260812 06:19:53.031201 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb): perf score=2.188937
I20260812 06:19:53.054632 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.023s	user 0.015s	sys 0.001s Metrics: {"bytes_written":4143684,"delete_count":0,"lbm_write_time_us":7088,"lbm_writes_lt_1ms":104,"reinsert_count":0,"update_count":505}
I20260812 06:19:53.055153 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb): perf score=2.188937
I20260812 06:19:53.066385 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4061634,"delete_count":0,"lbm_write_time_us":4230,"lbm_writes_lt_1ms":102,"reinsert_count":0,"update_count":495}
I20260812 06:19:53.067195 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling MajorDeltaCompactionOp(81415504b90b418f96e8487b7b562bcb): perf score=1.000000
I20260812 06:19:53.292779 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: MajorDeltaCompactionOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.225s	user 0.177s	sys 0.048s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979752,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":723,"lbm_read_time_us":16139,"lbm_reads_lt_1ms":774,"lbm_write_time_us":40152,"lbm_writes_lt_1ms":743,"mutex_wait_us":51,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":7680,"thread_start_us":75,"threads_started":1,"update_count":3500}
I20260812 06:19:53.293548 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb): perf score=18.063937
I20260812 06:19:53.383986 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.090s	user 0.037s	sys 0.040s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":37883,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":501,"reinsert_count":0,"update_count":2500}
I20260812 06:19:53.384462 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb): perf score=6.157687
I20260812 06:19:53.409646 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.025s	user 0.013s	sys 0.007s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":8975,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:53.410261 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling MajorDeltaCompactionOp(81415504b90b418f96e8487b7b562bcb): perf score=1.000000
I20260812 06:19:53.598537 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: MajorDeltaCompactionOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.188s	user 0.139s	sys 0.048s Metrics: {"cfile_cache_miss":732,"cfile_cache_miss_bytes":32979516,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":367,"lbm_read_time_us":13008,"lbm_reads_lt_1ms":764,"lbm_write_time_us":42078,"lbm_writes_lt_1ms":743,"mutex_wait_us":37,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":3500}
I20260812 06:19:53.599280 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb): perf score=18.063937
I20260812 06:19:53.677045 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.078s	user 0.049s	sys 0.028s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":35382,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":501,"reinsert_count":0,"update_count":2500}
I20260812 06:19:53.677764 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb): perf score=2.188937
I20260812 06:19:53.704326 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.026s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6787,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:53.704823 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb): perf score=2.188937
I20260812 06:19:53.716130 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4220,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:53.716794 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling MajorDeltaCompactionOp(81415504b90b418f96e8487b7b562bcb): perf score=1.000000
I20260812 06:19:53.925390 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: MajorDeltaCompactionOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.208s	user 0.159s	sys 0.049s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32979634,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":364,"lbm_read_time_us":16617,"lbm_reads_lt_1ms":773,"lbm_write_time_us":44566,"lbm_writes_lt_1ms":743,"mutex_wait_us":22,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":19584,"update_count":3500}
I20260812 06:19:53.925917 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb): perf score=14.095187
I20260812 06:19:53.979319 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.053s	user 0.031s	sys 0.020s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":24633,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:53.979861 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb): perf score=3.181125
I20260812 06:19:53.997324 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.017s	user 0.005s	sys 0.007s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4802,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:53.997838 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb): perf score=2.188937
I20260812 06:19:54.009380 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.011s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4195,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:54.010031 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling MajorDeltaCompactionOp(81415504b90b418f96e8487b7b562bcb): perf score=1.000000
I20260812 06:19:54.196094 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: MajorDeltaCompactionOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.186s	user 0.146s	sys 0.040s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877205,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":344,"lbm_read_time_us":14604,"lbm_reads_lt_1ms":673,"lbm_write_time_us":37849,"lbm_writes_lt_1ms":643,"mutex_wait_us":96,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":8192,"update_count":3000}
I20260812 06:19:54.196689 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb): perf score=14.095187
I20260812 06:19:54.253583 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.057s	user 0.028s	sys 0.028s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":25326,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:19:54.254244 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb): perf score=2.188937
I20260812 06:19:54.270566 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.016s	user 0.005s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6630,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:54.271157 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling MajorDeltaCompactionOp(81415504b90b418f96e8487b7b562bcb): perf score=1.000000
I20260812 06:19:54.453086 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: MajorDeltaCompactionOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.180s	user 0.107s	sys 0.061s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1074,"lbm_read_time_us":10829,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31517,"lbm_writes_lt_1ms":543,"mutex_wait_us":29,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3584,"update_count":2500}
I20260812 06:19:54.453778 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb): perf score=14.095187
I20260812 06:19:54.498342 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.044s	user 0.039s	sys 0.004s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19763,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:54.498839 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling FlushMRSOp(81415504b90b418f96e8487b7b562bcb): perf score=1.000000
I20260812 06:19:54.529543 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: FlushMRSOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.031s	user 0.026s	sys 0.004s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":88,"dirs.run_cpu_time_us":211,"dirs.run_wall_time_us":1546,"drs_written":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2097,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:19:54.530330 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling LogGCOp(81415504b90b418f96e8487b7b562bcb): free 129773839 bytes of WAL
I20260812 06:19:54.530625 21300 log_reader.cc:385] T 81415504b90b418f96e8487b7b562bcb: removed 13 log segments from log reader
I20260812 06:19:54.530692 21300 log.cc:1079] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/81415504b90b418f96e8487b7b562bcb/wal-000000027 (ops 129-133)
I20260812 06:19:54.530732 21300 log.cc:1079] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/81415504b90b418f96e8487b7b562bcb/wal-000000028 (ops 134-138)
I20260812 06:19:54.530755 21300 log.cc:1079] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/81415504b90b418f96e8487b7b562bcb/wal-000000029 (ops 139-143)
I20260812 06:19:54.530778 21300 log.cc:1079] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/81415504b90b418f96e8487b7b562bcb/wal-000000030 (ops 144-148)
I20260812 06:19:54.530808 21300 log.cc:1079] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/81415504b90b418f96e8487b7b562bcb/wal-000000031 (ops 149-153)
I20260812 06:19:54.530843 21300 log.cc:1079] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/81415504b90b418f96e8487b7b562bcb/wal-000000032 (ops 154-158)
I20260812 06:19:54.530877 21300 log.cc:1079] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/81415504b90b418f96e8487b7b562bcb/wal-000000033 (ops 159-162)
I20260812 06:19:54.530905 21300 log.cc:1079] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/81415504b90b418f96e8487b7b562bcb/wal-000000034 (ops 163-167)
I20260812 06:19:54.530927 21300 log.cc:1079] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/81415504b90b418f96e8487b7b562bcb/wal-000000035 (ops 168-172)
I20260812 06:19:54.530957 21300 log.cc:1079] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/81415504b90b418f96e8487b7b562bcb/wal-000000036 (ops 173-177)
I20260812 06:19:54.530982 21300 log.cc:1079] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/81415504b90b418f96e8487b7b562bcb/wal-000000037 (ops 178-182)
I20260812 06:19:54.531008 21300 log.cc:1079] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/81415504b90b418f96e8487b7b562bcb/wal-000000038 (ops 183-187)
I20260812 06:19:54.531032 21300 log.cc:1079] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/81415504b90b418f96e8487b7b562bcb/wal-000000039 (ops 188-192)
I20260812 06:19:54.561766 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: LogGCOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.031s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:19:54.562234 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb): perf score=3.181125
I20260812 06:19:54.577762 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.015s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4532,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:54.578287 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb): perf score=2.188937
I20260812 06:19:54.592113 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.014s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5241,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:54.592631 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling LogGCOp(81415504b90b418f96e8487b7b562bcb): free 11564893 bytes of WAL
I20260812 06:19:54.592969 21300 log_reader.cc:385] T 81415504b90b418f96e8487b7b562bcb: removed 1 log segments from log reader
I20260812 06:19:54.593046 21300 log.cc:1079] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc: Deleting log segment in path: /tmp/dist-test-taskrsZlw7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515583746304-20789-0/minicluster-data/ts-0-root/wals/81415504b90b418f96e8487b7b562bcb/wal-000000040 (ops 193-196)
I20260812 06:19:54.596464 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: LogGCOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.004s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:19:54.597139 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling UndoDeltaBlockGCOp(81415504b90b418f96e8487b7b562bcb): 493 bytes on disk
I20260812 06:19:54.597873 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: UndoDeltaBlockGCOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":129,"lbm_reads_lt_1ms":4}
I20260812 06:19:54.598865 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling MajorDeltaCompactionOp(81415504b90b418f96e8487b7b562bcb): perf score=1.000000
I20260812 06:19:54.737149 20789 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.007s	user 1.877s	sys 0.182s
I20260812 06:19:54.789186 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: MajorDeltaCompactionOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.190s	user 0.130s	sys 0.060s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877207,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"lbm_read_time_us":13279,"lbm_reads_lt_1ms":669,"lbm_write_time_us":35381,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:19:54.789675 21393 maintenance_manager.cc:419] P 7138e5b3a6d44a35b7be31fc932862bc: Scheduling FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb): perf score=10.126437
I20260812 06:19:54.820209 20789 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.083s	user 0.001s	sys 0.000s
I20260812 06:19:54.820734 20789 tablet_server.cc:179] TabletServer@127.20.77.65:0 shutting down...
I20260812 06:19:54.834887 21300 maintenance_manager.cc:643] P 7138e5b3a6d44a35b7be31fc932862bc: FlushDeltaMemStoresOp(81415504b90b418f96e8487b7b562bcb) complete. Timing: real 0.045s	user 0.027s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":19347,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:54.835752 20789 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:54.836086 20789 tablet_replica.cc:333] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc: stopping tablet replica
I20260812 06:19:54.836294 20789 raft_consensus.cc:2243] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:54.836517 20789 raft_consensus.cc:2272] T 81415504b90b418f96e8487b7b562bcb P 7138e5b3a6d44a35b7be31fc932862bc [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:54.847568 20789 tablet_server.cc:196] TabletServer@127.20.77.65:0 shutdown complete.
I20260812 06:19:54.850986 20789 master.cc:562] Master@127.20.77.126:40575 shutting down...
I20260812 06:19:54.854378 20789 raft_consensus.cc:2243] T 00000000000000000000000000000000 P e6c4598b34024f09aaa60f65c823daac [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:54.854558 20789 raft_consensus.cc:2272] T 00000000000000000000000000000000 P e6c4598b34024f09aaa60f65c823daac [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:54.854619 20789 tablet_replica.cc:333] T 00000000000000000000000000000000 P e6c4598b34024f09aaa60f65c823daac: stopping tablet replica
I20260812 06:19:54.867403 20789 master.cc:584] Master@127.20.77.126:40575 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5498 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11196 ms total)

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