[==========] 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:46.160356 30002 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.29.76.190:45277
I20260812 06:19:46.161417 30002 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:46.162065 30002 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:46.169203 30009 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:46.169252 30002 server_base.cc:1061] running on GCE node
W20260812 06:19:46.169215 30008 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:46.169538 30012 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:46.170058 30002 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:46.170189 30002 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:46.170256 30002 hybrid_clock.cc:648] HybridClock initialized: now 1786515586170253 us; error 0 us; skew 500 ppm
I20260812 06:19:46.172183 30002 webserver.cc:533] Webserver started at http://127.29.76.190:43523/ using document root <none> and password file <none>
I20260812 06:19:46.172765 30002 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:46.172856 30002 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:46.173107 30002 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:46.174782 30002 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586149177-30002-0/minicluster-data/master-0-root/instance:
uuid: "be9ff8b160ef4acf83ae04fef9a044d2"
format_stamp: "Formatted at 2026-08-12 06:19:46 on dist-test-slave-1zqn"
I20260812 06:19:46.178545 30002 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.000s	sys 0.005s
I20260812 06:19:46.180794 30017 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:46.181773 30002 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.001s	sys 0.002s
I20260812 06:19:46.181908 30002 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586149177-30002-0/minicluster-data/master-0-root
uuid: "be9ff8b160ef4acf83ae04fef9a044d2"
format_stamp: "Formatted at 2026-08-12 06:19:46 on dist-test-slave-1zqn"
I20260812 06:19:46.182107 30002 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586149177-30002-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586149177-30002-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586149177-30002-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:46.200322 30002 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:46.201067 30002 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:46.201278 30002 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:46.210250 30002 rpc_server.cc:307] RPC server started. Bound to: 127.29.76.190:45277
I20260812 06:19:46.210247 30078 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.29.76.190:45277 every 8 connection(s)
I20260812 06:19:46.212738 30079 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:46.218394 30079 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P be9ff8b160ef4acf83ae04fef9a044d2: Bootstrap starting.
I20260812 06:19:46.221110 30079 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P be9ff8b160ef4acf83ae04fef9a044d2: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:46.222146 30079 log.cc:826] T 00000000000000000000000000000000 P be9ff8b160ef4acf83ae04fef9a044d2: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:46.224176 30079 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P be9ff8b160ef4acf83ae04fef9a044d2: No bootstrap required, opened a new log
I20260812 06:19:46.227358 30079 raft_consensus.cc:359] T 00000000000000000000000000000000 P be9ff8b160ef4acf83ae04fef9a044d2 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "be9ff8b160ef4acf83ae04fef9a044d2" member_type: VOTER }
I20260812 06:19:46.227584 30079 raft_consensus.cc:385] T 00000000000000000000000000000000 P be9ff8b160ef4acf83ae04fef9a044d2 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:46.227629 30079 raft_consensus.cc:740] T 00000000000000000000000000000000 P be9ff8b160ef4acf83ae04fef9a044d2 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: be9ff8b160ef4acf83ae04fef9a044d2, State: Initialized, Role: FOLLOWER
I20260812 06:19:46.228436 30079 consensus_queue.cc:260] T 00000000000000000000000000000000 P be9ff8b160ef4acf83ae04fef9a044d2 [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: "be9ff8b160ef4acf83ae04fef9a044d2" member_type: VOTER }
I20260812 06:19:46.228677 30079 raft_consensus.cc:399] T 00000000000000000000000000000000 P be9ff8b160ef4acf83ae04fef9a044d2 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:46.228757 30079 raft_consensus.cc:493] T 00000000000000000000000000000000 P be9ff8b160ef4acf83ae04fef9a044d2 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:46.228943 30079 raft_consensus.cc:3060] T 00000000000000000000000000000000 P be9ff8b160ef4acf83ae04fef9a044d2 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:46.229871 30079 raft_consensus.cc:515] T 00000000000000000000000000000000 P be9ff8b160ef4acf83ae04fef9a044d2 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "be9ff8b160ef4acf83ae04fef9a044d2" member_type: VOTER }
I20260812 06:19:46.230397 30079 leader_election.cc:304] T 00000000000000000000000000000000 P be9ff8b160ef4acf83ae04fef9a044d2 [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: be9ff8b160ef4acf83ae04fef9a044d2; no voters: 
I20260812 06:19:46.230767 30079 leader_election.cc:290] T 00000000000000000000000000000000 P be9ff8b160ef4acf83ae04fef9a044d2 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:46.230966 30083 raft_consensus.cc:2804] T 00000000000000000000000000000000 P be9ff8b160ef4acf83ae04fef9a044d2 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:46.231288 30083 raft_consensus.cc:697] T 00000000000000000000000000000000 P be9ff8b160ef4acf83ae04fef9a044d2 [term 1 LEADER]: Becoming Leader. State: Replica: be9ff8b160ef4acf83ae04fef9a044d2, State: Running, Role: LEADER
I20260812 06:19:46.231757 30083 consensus_queue.cc:237] T 00000000000000000000000000000000 P be9ff8b160ef4acf83ae04fef9a044d2 [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: "be9ff8b160ef4acf83ae04fef9a044d2" member_type: VOTER }
I20260812 06:19:46.231930 30079 sys_catalog.cc:565] T 00000000000000000000000000000000 P be9ff8b160ef4acf83ae04fef9a044d2 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:46.234113 30085 sys_catalog.cc:455] T 00000000000000000000000000000000 P be9ff8b160ef4acf83ae04fef9a044d2 [sys.catalog]: SysCatalogTable state changed. Reason: New leader be9ff8b160ef4acf83ae04fef9a044d2. Latest consensus state: current_term: 1 leader_uuid: "be9ff8b160ef4acf83ae04fef9a044d2" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "be9ff8b160ef4acf83ae04fef9a044d2" member_type: VOTER } }
I20260812 06:19:46.234122 30084 sys_catalog.cc:455] T 00000000000000000000000000000000 P be9ff8b160ef4acf83ae04fef9a044d2 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "be9ff8b160ef4acf83ae04fef9a044d2" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "be9ff8b160ef4acf83ae04fef9a044d2" member_type: VOTER } }
I20260812 06:19:46.234284 30085 sys_catalog.cc:458] T 00000000000000000000000000000000 P be9ff8b160ef4acf83ae04fef9a044d2 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:46.234292 30084 sys_catalog.cc:458] T 00000000000000000000000000000000 P be9ff8b160ef4acf83ae04fef9a044d2 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:46.234670 30099 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:46.234687 30002 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:46.237174 30099 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:46.242599 30099 catalog_manager.cc:1383] Generated new cluster ID: 396b7a4115c44e1f9b81411bf20fe95f
I20260812 06:19:46.242686 30099 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:46.260022 30099 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:46.260994 30099 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:46.275100 30099 catalog_manager.cc:6092] T 00000000000000000000000000000000 P be9ff8b160ef4acf83ae04fef9a044d2: Generated new TSK 0
I20260812 06:19:46.275882 30099 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:46.299839 30002 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:46.302966 30105 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:46.303025 30108 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:46.303045 30106 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:46.303525 30002 server_base.cc:1061] running on GCE node
I20260812 06:19:46.303716 30002 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:46.303768 30002 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:46.303791 30002 hybrid_clock.cc:648] HybridClock initialized: now 1786515586303791 us; error 0 us; skew 500 ppm
I20260812 06:19:46.304783 30002 webserver.cc:533] Webserver started at http://127.29.76.129:44843/ using document root <none> and password file <none>
I20260812 06:19:46.304960 30002 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:46.305022 30002 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:46.305101 30002 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:46.305583 30002 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586149177-30002-0/minicluster-data/ts-0-root/instance:
uuid: "b595af587a324ce88712468c5be35ced"
format_stamp: "Formatted at 2026-08-12 06:19:46 on dist-test-slave-1zqn"
I20260812 06:19:46.307538 30002 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:19:46.308753 30114 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:46.309108 30002 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:46.309186 30002 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586149177-30002-0/minicluster-data/ts-0-root
uuid: "b595af587a324ce88712468c5be35ced"
format_stamp: "Formatted at 2026-08-12 06:19:46 on dist-test-slave-1zqn"
I20260812 06:19:46.309276 30002 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586149177-30002-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586149177-30002-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586149177-30002-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:46.318604 30002 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:46.319202 30002 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:46.319756 30002 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:46.320657 30002 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:46.320706 30002 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:46.320772 30002 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:46.320812 30002 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:46.327736 30002 rpc_server.cc:307] RPC server started. Bound to: 127.29.76.129:45773
I20260812 06:19:46.327804 30186 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.29.76.129:45773 every 8 connection(s)
I20260812 06:19:46.342183 30187 heartbeater.cc:344] Connected to a master server at 127.29.76.190:45277
I20260812 06:19:46.342473 30187 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:46.342995 30187 heartbeater.cc:507] Master 127.29.76.190:45277 requested a full tablet report, sending...
I20260812 06:19:46.344566 30036 ts_manager.cc:194] Registered new tserver with Master: b595af587a324ce88712468c5be35ced (127.29.76.129:45773)
I20260812 06:19:46.344736 30002 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.016203473s
I20260812 06:19:46.346225 30036 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:44320
I20260812 06:19:46.355167 30036 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:44334:
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:46.372741 30147 tablet_service.cc:1511] Processing CreateTablet for tablet e6c1643565424e858f0818cf9f31c4e5 (DEFAULT_TABLE table=heavy-update-compaction-test [id=73bc219d82754688a3a05115bcbf30f6]), partition=
I20260812 06:19:46.373226 30147 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet e6c1643565424e858f0818cf9f31c4e5. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:46.375895 30202 tablet_bootstrap.cc:492] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced: Bootstrap starting.
I20260812 06:19:46.376951 30202 tablet_bootstrap.cc:654] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:46.378162 30202 tablet_bootstrap.cc:492] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced: No bootstrap required, opened a new log
I20260812 06:19:46.378291 30202 ts_tablet_manager.cc:1403] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:46.378826 30202 raft_consensus.cc:359] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b595af587a324ce88712468c5be35ced" member_type: VOTER last_known_addr { host: "127.29.76.129" port: 45773 } }
I20260812 06:19:46.378954 30202 raft_consensus.cc:385] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:46.379034 30202 raft_consensus.cc:740] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: b595af587a324ce88712468c5be35ced, State: Initialized, Role: FOLLOWER
I20260812 06:19:46.379261 30202 consensus_queue.cc:260] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced [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: "b595af587a324ce88712468c5be35ced" member_type: VOTER last_known_addr { host: "127.29.76.129" port: 45773 } }
I20260812 06:19:46.379374 30202 raft_consensus.cc:399] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:46.379438 30202 raft_consensus.cc:493] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:46.379498 30202 raft_consensus.cc:3060] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:46.380363 30202 raft_consensus.cc:515] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b595af587a324ce88712468c5be35ced" member_type: VOTER last_known_addr { host: "127.29.76.129" port: 45773 } }
I20260812 06:19:46.380535 30202 leader_election.cc:304] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced [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: b595af587a324ce88712468c5be35ced; no voters: 
I20260812 06:19:46.380797 30202 leader_election.cc:290] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:46.380915 30205 raft_consensus.cc:2804] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:46.381182 30202 ts_tablet_manager.cc:1434] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:19:46.381153 30205 raft_consensus.cc:697] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced [term 1 LEADER]: Becoming Leader. State: Replica: b595af587a324ce88712468c5be35ced, State: Running, Role: LEADER
I20260812 06:19:46.381403 30187 heartbeater.cc:499] Master 127.29.76.190:45277 was elected leader, sending a full tablet report...
I20260812 06:19:46.381551 30205 consensus_queue.cc:237] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced [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: "b595af587a324ce88712468c5be35ced" member_type: VOTER last_known_addr { host: "127.29.76.129" port: 45773 } }
I20260812 06:19:46.384778 30036 catalog_manager.cc:5719] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced reported cstate change: term changed from 0 to 1, leader changed from <none> to b595af587a324ce88712468c5be35ced (127.29.76.129). New cstate: current_term: 1 leader_uuid: "b595af587a324ce88712468c5be35ced" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b595af587a324ce88712468c5be35ced" member_type: VOTER last_known_addr { host: "127.29.76.129" port: 45773 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:46.450341 30002 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.057s	user 0.022s	sys 0.004s
I20260812 06:19:46.579135 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling FlushMRSOp(e6c1643565424e858f0818cf9f31c4e5): perf score=15.086190
I20260812 06:19:46.755625 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: FlushMRSOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.176s	user 0.146s	sys 0.024s Metrics: {"bytes_written":11897250,"cfile_init":1,"compiler_manager_pool.queue_time_us":243,"delete_count":0,"dirs.queue_time_us":39,"dirs.run_cpu_time_us":194,"dirs.run_wall_time_us":987,"drs_written":1,"lbm_read_time_us":78,"lbm_reads_lt_1ms":4,"lbm_write_time_us":44814,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":161,"threads_started":1,"update_count":1450}
I20260812 06:19:46.757064 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling LogGCOp(e6c1643565424e858f0818cf9f31c4e5): free 20743880 bytes of WAL
I20260812 06:19:46.757405 30119 log_reader.cc:385] T e6c1643565424e858f0818cf9f31c4e5: removed 2 log segments from log reader
I20260812 06:19:46.757478 30119 log.cc:1079] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/e6c1643565424e858f0818cf9f31c4e5/wal-000000001 (ops 1-6)
I20260812 06:19:46.757535 30119 log.cc:1079] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/e6c1643565424e858f0818cf9f31c4e5/wal-000000002 (ops 7-11)
I20260812 06:19:46.764274 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: LogGCOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.007s	user 0.000s	sys 0.007s Metrics: {}
I20260812 06:19:46.764955 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling UndoDeltaBlockGCOp(e6c1643565424e858f0818cf9f31c4e5): 12719216 bytes on disk
I20260812 06:19:46.765954 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: UndoDeltaBlockGCOp(e6c1643565424e858f0818cf9f31c4e5) 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:46.766541 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5): perf score=2.188937
I20260812 06:19:46.786490 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.020s	user 0.004s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6854,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:46.786986 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling MajorDeltaCompactionOp(e6c1643565424e858f0818cf9f31c4e5): perf score=1.000000
I20260812 06:19:46.930819 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: MajorDeltaCompactionOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.144s	user 0.117s	sys 0.024s Metrics: {"cfile_cache_miss":422,"cfile_cache_miss_bytes":20262037,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":602,"lbm_read_time_us":7807,"lbm_reads_lt_1ms":450,"lbm_write_time_us":28202,"lbm_writes_lt_1ms":433,"peak_mem_usage":49238594,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":328,"threads_started":5,"update_count":1950}
I20260812 06:19:46.931423 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5): perf score=11.118625
I20260812 06:19:46.966908 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.035s	user 0.024s	sys 0.009s Metrics: {"bytes_written":12717740,"delete_count":0,"lbm_write_time_us":15624,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:46.967553 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5): perf score=2.188937
I20260812 06:19:46.989691 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.022s	user 0.004s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5136,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:46.990128 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5): perf score=2.188937
I20260812 06:19:47.000651 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.010s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3977,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:47.001158 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling MajorDeltaCompactionOp(e6c1643565424e858f0818cf9f31c4e5): perf score=1.000000
I20260812 06:19:47.159276 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: MajorDeltaCompactionOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.158s	user 0.128s	sys 0.028s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774803,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1208,"lbm_read_time_us":12218,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29358,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6400,"update_count":2500}
I20260812 06:19:47.159739 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5): perf score=11.118625
I20260812 06:19:47.204989 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.045s	user 0.024s	sys 0.019s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17080,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:47.205561 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5): perf score=2.188937
I20260812 06:19:47.230433 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.025s	user 0.010s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5820,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:47.231004 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5): perf score=2.188937
I20260812 06:19:47.242770 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4405,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:47.243330 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling MajorDeltaCompactionOp(e6c1643565424e858f0818cf9f31c4e5): perf score=1.000000
I20260812 06:19:47.417754 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: MajorDeltaCompactionOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.173s	user 0.118s	sys 0.053s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1178,"lbm_read_time_us":12192,"lbm_reads_lt_1ms":573,"lbm_write_time_us":34237,"lbm_writes_lt_1ms":543,"mutex_wait_us":403,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3840,"update_count":2500}
I20260812 06:19:47.418509 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5): perf score=12.110812
I20260812 06:19:47.466341 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.048s	user 0.020s	sys 0.023s Metrics: {"bytes_written":13702314,"delete_count":0,"lbm_write_time_us":18866,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":336,"reinsert_count":0,"update_count":1670}
I20260812 06:19:47.466902 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5): perf score=1.196750
I20260812 06:19:47.483924 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.017s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3118059,"delete_count":0,"lbm_write_time_us":5021,"lbm_writes_lt_1ms":79,"reinsert_count":0,"update_count":380}
I20260812 06:19:47.484517 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5): perf score=2.188937
I20260812 06:19:47.495065 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3809,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:47.495743 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling MajorDeltaCompactionOp(e6c1643565424e858f0818cf9f31c4e5): perf score=1.000000
I20260812 06:19:47.677316 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: MajorDeltaCompactionOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.181s	user 0.109s	sys 0.067s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774778,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1269,"lbm_read_time_us":12051,"lbm_reads_lt_1ms":573,"lbm_write_time_us":32376,"lbm_writes_lt_1ms":543,"mutex_wait_us":390,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":135680,"update_count":2500}
I20260812 06:19:47.677834 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5): perf score=14.095187
I20260812 06:19:47.739483 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.061s	user 0.036s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24899,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:47.740299 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling MajorDeltaCompactionOp(e6c1643565424e858f0818cf9f31c4e5): perf score=1.000000
I20260812 06:19:47.902894 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: MajorDeltaCompactionOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.162s	user 0.097s	sys 0.053s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":757,"lbm_read_time_us":11529,"lbm_reads_lt_1ms":463,"lbm_write_time_us":24888,"lbm_writes_lt_1ms":443,"mutex_wait_us":369,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5760,"update_count":2000}
I20260812 06:19:47.903638 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5): perf score=14.095187
I20260812 06:19:47.954958 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.051s	user 0.025s	sys 0.023s Metrics: {"bytes_written":16409950,"delete_count":0,"lbm_write_time_us":21896,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:47.955565 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5): perf score=2.188937
I20260812 06:19:47.973021 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.017s	user 0.009s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6668,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:47.973493 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling MajorDeltaCompactionOp(e6c1643565424e858f0818cf9f31c4e5): perf score=1.000000
I20260812 06:19:48.158032 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: MajorDeltaCompactionOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.184s	user 0.137s	sys 0.037s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774737,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":450,"lbm_read_time_us":10500,"lbm_reads_lt_1ms":564,"lbm_write_time_us":32412,"lbm_writes_lt_1ms":543,"mutex_wait_us":98,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:19:48.158726 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5): perf score=14.095187
I20260812 06:19:48.216797 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.058s	user 0.031s	sys 0.008s Metrics: {"bytes_written":16409914,"delete_count":0,"lbm_write_time_us":17634,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:48.217299 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5): perf score=2.188937
I20260812 06:19:48.230322 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.013s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5008,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:48.231160 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling FlushMRSOp(e6c1643565424e858f0818cf9f31c4e5): perf score=1.000000
I20260812 06:19:48.269201 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: FlushMRSOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.038s	user 0.033s	sys 0.004s Metrics: {"bytes_written":1316413,"cfile_init":1,"dirs.queue_time_us":66,"dirs.run_cpu_time_us":270,"dirs.run_wall_time_us":1493,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1850,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:19:48.270332 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling LogGCOp(e6c1643565424e858f0818cf9f31c4e5): free 132571317 bytes of WAL
I20260812 06:19:48.270670 30119 log_reader.cc:385] T e6c1643565424e858f0818cf9f31c4e5: removed 13 log segments from log reader
I20260812 06:19:48.270745 30119 log.cc:1079] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/e6c1643565424e858f0818cf9f31c4e5/wal-000000003 (ops 12-16)
I20260812 06:19:48.270802 30119 log.cc:1079] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/e6c1643565424e858f0818cf9f31c4e5/wal-000000004 (ops 17-21)
I20260812 06:19:48.270859 30119 log.cc:1079] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/e6c1643565424e858f0818cf9f31c4e5/wal-000000005 (ops 22-26)
I20260812 06:19:48.270900 30119 log.cc:1079] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/e6c1643565424e858f0818cf9f31c4e5/wal-000000006 (ops 27-31)
I20260812 06:19:48.270936 30119 log.cc:1079] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/e6c1643565424e858f0818cf9f31c4e5/wal-000000007 (ops 32-36)
I20260812 06:19:48.270973 30119 log.cc:1079] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/e6c1643565424e858f0818cf9f31c4e5/wal-000000008 (ops 37-41)
I20260812 06:19:48.271008 30119 log.cc:1079] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/e6c1643565424e858f0818cf9f31c4e5/wal-000000009 (ops 42-46)
I20260812 06:19:48.271046 30119 log.cc:1079] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/e6c1643565424e858f0818cf9f31c4e5/wal-000000010 (ops 47-50)
I20260812 06:19:48.271081 30119 log.cc:1079] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/e6c1643565424e858f0818cf9f31c4e5/wal-000000011 (ops 51-55)
I20260812 06:19:48.271150 30119 log.cc:1079] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/e6c1643565424e858f0818cf9f31c4e5/wal-000000012 (ops 56-60)
I20260812 06:19:48.271185 30119 log.cc:1079] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/e6c1643565424e858f0818cf9f31c4e5/wal-000000013 (ops 61-65)
I20260812 06:19:48.271220 30119 log.cc:1079] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/e6c1643565424e858f0818cf9f31c4e5/wal-000000014 (ops 66-70)
I20260812 06:19:48.271257 30119 log.cc:1079] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/e6c1643565424e858f0818cf9f31c4e5/wal-000000015 (ops 71-74)
I20260812 06:19:48.303944 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: LogGCOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.033s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:19:48.308487 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5): perf score=6.157687
I20260812 06:19:48.336406 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.027s	user 0.016s	sys 0.010s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":11216,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:48.336948 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling UndoDeltaBlockGCOp(e6c1643565424e858f0818cf9f31c4e5): 496 bytes on disk
I20260812 06:19:48.337450 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: UndoDeltaBlockGCOp(e6c1643565424e858f0818cf9f31c4e5) 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:48.337988 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling MajorDeltaCompactionOp(e6c1643565424e858f0818cf9f31c4e5): perf score=1.000000
I20260812 06:19:48.588172 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: MajorDeltaCompactionOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.250s	user 0.166s	sys 0.077s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32979645,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":544,"lbm_read_time_us":18957,"lbm_reads_lt_1ms":769,"lbm_write_time_us":41003,"lbm_writes_lt_1ms":743,"mutex_wait_us":29,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":10496,"thread_start_us":147,"threads_started":1,"update_count":3500}
I20260812 06:19:48.589027 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5): perf score=18.063937
I20260812 06:19:48.674705 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.085s	user 0.053s	sys 0.023s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":35896,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:48.675312 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5): perf score=2.188937
I20260812 06:19:48.688824 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.013s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4482,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:48.689420 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling MajorDeltaCompactionOp(e6c1643565424e858f0818cf9f31c4e5): perf score=1.000000
I20260812 06:19:48.905395 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: MajorDeltaCompactionOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.215s	user 0.143s	sys 0.072s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877103,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":237,"lbm_read_time_us":16074,"lbm_reads_lt_1ms":672,"lbm_write_time_us":34340,"lbm_writes_lt_1ms":643,"mutex_wait_us":51,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":5632,"update_count":3000}
I20260812 06:19:48.906306 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5): perf score=14.095187
I20260812 06:19:48.962667 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.056s	user 0.025s	sys 0.028s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":23695,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:48.963212 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5): perf score=2.188937
I20260812 06:19:48.982055 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.019s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5836,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:48.982640 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling MajorDeltaCompactionOp(e6c1643565424e858f0818cf9f31c4e5): perf score=1.000000
I20260812 06:19:49.155829 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: MajorDeltaCompactionOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.173s	user 0.134s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774685,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":373,"lbm_read_time_us":11903,"lbm_reads_lt_1ms":564,"lbm_write_time_us":28939,"lbm_writes_lt_1ms":543,"mutex_wait_us":36,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":61568,"update_count":2500}
I20260812 06:19:49.156641 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5): perf score=15.087375
I20260812 06:19:49.208245 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.051s	user 0.028s	sys 0.023s Metrics: {"bytes_written":16820139,"delete_count":0,"lbm_write_time_us":22795,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:19:49.208863 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5): perf score=2.188937
I20260812 06:19:49.223754 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.014s	user 0.005s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5317,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:49.224298 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling MajorDeltaCompactionOp(e6c1643565424e858f0818cf9f31c4e5): perf score=1.000000
I20260812 06:19:49.386847 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: MajorDeltaCompactionOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.162s	user 0.089s	sys 0.073s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774672,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":303,"lbm_read_time_us":12166,"lbm_reads_lt_1ms":564,"lbm_write_time_us":28849,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12160,"update_count":2500}
I20260812 06:19:49.387399 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5): perf score=14.095187
I20260812 06:19:49.450747 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.063s	user 0.028s	sys 0.022s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":19250,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:49.451370 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5): perf score=2.188937
I20260812 06:19:49.462473 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4408,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:49.462940 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling MajorDeltaCompactionOp(e6c1643565424e858f0818cf9f31c4e5): perf score=1.000000
I20260812 06:19:49.645046 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: MajorDeltaCompactionOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.182s	user 0.141s	sys 0.039s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":36,"lbm_read_time_us":13530,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32016,"lbm_writes_lt_1ms":543,"mutex_wait_us":69,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:49.645797 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5): perf score=11.118625
I20260812 06:19:49.685527 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.040s	user 0.026s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16920,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:49.686048 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5): perf score=2.188937
I20260812 06:19:49.718219 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.032s	user 0.009s	sys 0.011s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4633,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:49.718775 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5): perf score=2.188937
I20260812 06:19:49.729652 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4200,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:49.730115 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling FlushMRSOp(e6c1643565424e858f0818cf9f31c4e5): perf score=1.000000
I20260812 06:19:49.776248 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: FlushMRSOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.046s	user 0.035s	sys 0.000s Metrics: {"bytes_written":1152512,"cfile_init":1,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":276,"dirs.run_wall_time_us":1544,"drs_written":1,"lbm_read_time_us":86,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1631,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:49.777000 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling LogGCOp(e6c1643565424e858f0818cf9f31c4e5): free 112239316 bytes of WAL
I20260812 06:19:49.777235 30119 log_reader.cc:385] T e6c1643565424e858f0818cf9f31c4e5: removed 11 log segments from log reader
I20260812 06:19:49.777279 30119 log.cc:1079] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/e6c1643565424e858f0818cf9f31c4e5/wal-000000016 (ops 75-79)
I20260812 06:19:49.777308 30119 log.cc:1079] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/e6c1643565424e858f0818cf9f31c4e5/wal-000000017 (ops 80-84)
I20260812 06:19:49.777375 30119 log.cc:1079] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/e6c1643565424e858f0818cf9f31c4e5/wal-000000018 (ops 85-89)
I20260812 06:19:49.777402 30119 log.cc:1079] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/e6c1643565424e858f0818cf9f31c4e5/wal-000000019 (ops 90-94)
I20260812 06:19:49.777442 30119 log.cc:1079] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/e6c1643565424e858f0818cf9f31c4e5/wal-000000020 (ops 95-99)
I20260812 06:19:49.777486 30119 log.cc:1079] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/e6c1643565424e858f0818cf9f31c4e5/wal-000000021 (ops 100-104)
I20260812 06:19:49.777524 30119 log.cc:1079] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/e6c1643565424e858f0818cf9f31c4e5/wal-000000022 (ops 105-108)
I20260812 06:19:49.777565 30119 log.cc:1079] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/e6c1643565424e858f0818cf9f31c4e5/wal-000000023 (ops 109-113)
I20260812 06:19:49.777601 30119 log.cc:1079] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/e6c1643565424e858f0818cf9f31c4e5/wal-000000024 (ops 114-118)
I20260812 06:19:49.777639 30119 log.cc:1079] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/e6c1643565424e858f0818cf9f31c4e5/wal-000000025 (ops 119-123)
I20260812 06:19:49.777678 30119 log.cc:1079] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/e6c1643565424e858f0818cf9f31c4e5/wal-000000026 (ops 124-128)
I20260812 06:19:49.801614 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: LogGCOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.024s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:19:49.802125 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling UndoDeltaBlockGCOp(e6c1643565424e858f0818cf9f31c4e5): 446 bytes on disk
I20260812 06:19:49.802585 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: UndoDeltaBlockGCOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4}
I20260812 06:19:49.803135 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5): perf score=2.188937
I20260812 06:19:49.819832 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.017s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4308,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:49.820323 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5): perf score=2.188937
I20260812 06:19:49.832158 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4423,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:49.832767 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling MajorDeltaCompactionOp(e6c1643565424e858f0818cf9f31c4e5): perf score=1.000000
I20260812 06:19:50.087596 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: MajorDeltaCompactionOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.254s	user 0.155s	sys 0.092s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979860,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":2252,"lbm_read_time_us":16958,"lbm_reads_lt_1ms":775,"lbm_write_time_us":39451,"lbm_writes_lt_1ms":743,"mutex_wait_us":1692,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":118,"threads_started":1,"update_count":3500}
I20260812 06:19:50.088356 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5): perf score=18.063937
I20260812 06:19:50.160557 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.072s	user 0.033s	sys 0.024s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":26395,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:50.161106 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5): perf score=2.188937
I20260812 06:19:50.173769 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4336,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:50.174364 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling MajorDeltaCompactionOp(e6c1643565424e858f0818cf9f31c4e5): perf score=1.000000
I20260812 06:19:50.413434 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: MajorDeltaCompactionOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.239s	user 0.160s	sys 0.071s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877103,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":214,"lbm_read_time_us":15587,"lbm_reads_lt_1ms":672,"lbm_write_time_us":39416,"lbm_writes_lt_1ms":643,"mutex_wait_us":53,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":91264,"update_count":3000}
I20260812 06:19:50.414255 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5): perf score=18.063937
I20260812 06:19:50.489106 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.075s	user 0.038s	sys 0.031s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":33230,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":501,"reinsert_count":0,"update_count":2500}
I20260812 06:19:50.489706 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5): perf score=2.188937
I20260812 06:19:50.501477 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4331,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:50.502032 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling MajorDeltaCompactionOp(e6c1643565424e858f0818cf9f31c4e5): perf score=1.000000
I20260812 06:19:50.714205 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: MajorDeltaCompactionOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.212s	user 0.152s	sys 0.059s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877103,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1431,"lbm_read_time_us":15178,"lbm_reads_lt_1ms":672,"lbm_write_time_us":39819,"lbm_writes_lt_1ms":643,"mutex_wait_us":450,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:19:50.715067 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5): perf score=14.095187
I20260812 06:19:50.772768 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.057s	user 0.026s	sys 0.031s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":25432,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:50.773317 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5): perf score=2.188937
I20260812 06:19:50.787897 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5257,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:50.788437 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling MajorDeltaCompactionOp(e6c1643565424e858f0818cf9f31c4e5): perf score=1.000000
I20260812 06:19:50.971132 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: MajorDeltaCompactionOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.183s	user 0.116s	sys 0.062s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":821,"lbm_read_time_us":12397,"lbm_reads_lt_1ms":564,"lbm_write_time_us":34082,"lbm_writes_lt_1ms":543,"mutex_wait_us":74,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:19:50.972150 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5): perf score=15.087375
I20260812 06:19:51.023715 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.051s	user 0.030s	sys 0.016s Metrics: {"bytes_written":17148340,"delete_count":0,"lbm_write_time_us":22284,"lbm_writes_lt_1ms":421,"reinsert_count":0,"update_count":2090}
I20260812 06:19:51.024398 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5): perf score=2.188937
I20260812 06:19:51.048475 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.024s	user 0.011s	sys 0.001s Metrics: {"bytes_written":3774460,"delete_count":0,"lbm_write_time_us":4596,"lbm_writes_lt_1ms":95,"reinsert_count":0,"update_count":460}
I20260812 06:19:51.049065 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5): perf score=2.188937
I20260812 06:19:51.058993 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3664,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:51.059544 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling MajorDeltaCompactionOp(e6c1643565424e858f0818cf9f31c4e5): perf score=1.000000
I20260812 06:19:51.252257 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: MajorDeltaCompactionOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.193s	user 0.129s	sys 0.063s 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":180,"lbm_read_time_us":14775,"lbm_reads_lt_1ms":673,"lbm_write_time_us":31241,"lbm_writes_lt_1ms":643,"mutex_wait_us":56,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7424,"update_count":3000}
I20260812 06:19:51.253065 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5): perf score=14.095187
I20260812 06:19:51.295991 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.043s	user 0.014s	sys 0.025s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18960,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:51.296633 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5): perf score=2.188937
I20260812 06:19:51.310607 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5305,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:51.311128 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling FlushMRSOp(e6c1643565424e858f0818cf9f31c4e5): perf score=1.000000
I20260812 06:19:51.345492 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: FlushMRSOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.034s	user 0.029s	sys 0.004s Metrics: {"bytes_written":1234477,"cfile_init":1,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":259,"dirs.run_wall_time_us":1585,"drs_written":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1821,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:51.346200 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling LogGCOp(e6c1643565424e858f0818cf9f31c4e5): free 121459759 bytes of WAL
I20260812 06:19:51.346468 30119 log_reader.cc:385] T e6c1643565424e858f0818cf9f31c4e5: removed 12 log segments from log reader
I20260812 06:19:51.346514 30119 log.cc:1079] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/e6c1643565424e858f0818cf9f31c4e5/wal-000000027 (ops 129-133)
I20260812 06:19:51.346545 30119 log.cc:1079] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/e6c1643565424e858f0818cf9f31c4e5/wal-000000028 (ops 134-138)
I20260812 06:19:51.346654 30119 log.cc:1079] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/e6c1643565424e858f0818cf9f31c4e5/wal-000000029 (ops 139-143)
I20260812 06:19:51.346694 30119 log.cc:1079] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/e6c1643565424e858f0818cf9f31c4e5/wal-000000030 (ops 144-148)
I20260812 06:19:51.346720 30119 log.cc:1079] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/e6c1643565424e858f0818cf9f31c4e5/wal-000000031 (ops 149-153)
I20260812 06:19:51.346771 30119 log.cc:1079] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/e6c1643565424e858f0818cf9f31c4e5/wal-000000032 (ops 154-158)
I20260812 06:19:51.346812 30119 log.cc:1079] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/e6c1643565424e858f0818cf9f31c4e5/wal-000000033 (ops 159-163)
I20260812 06:19:51.346849 30119 log.cc:1079] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/e6c1643565424e858f0818cf9f31c4e5/wal-000000034 (ops 164-168)
I20260812 06:19:51.346887 30119 log.cc:1079] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/e6c1643565424e858f0818cf9f31c4e5/wal-000000035 (ops 169-173)
I20260812 06:19:51.346925 30119 log.cc:1079] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/e6c1643565424e858f0818cf9f31c4e5/wal-000000036 (ops 174-178)
I20260812 06:19:51.346961 30119 log.cc:1079] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/e6c1643565424e858f0818cf9f31c4e5/wal-000000037 (ops 179-183)
I20260812 06:19:51.346998 30119 log.cc:1079] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/e6c1643565424e858f0818cf9f31c4e5/wal-000000038 (ops 184-188)
I20260812 06:19:51.375730 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: LogGCOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.029s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:51.376293 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5): perf score=3.181125
I20260812 06:19:51.389889 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.013s	user 0.006s	sys 0.005s Metrics: {"bytes_written":5005190,"delete_count":0,"lbm_write_time_us":5563,"lbm_writes_lt_1ms":125,"reinsert_count":0,"update_count":610}
I20260812 06:19:51.390396 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling LogGCOp(e6c1643565424e858f0818cf9f31c4e5): free 11564893 bytes of WAL
I20260812 06:19:51.390625 30119 log_reader.cc:385] T e6c1643565424e858f0818cf9f31c4e5: removed 1 log segments from log reader
I20260812 06:19:51.390668 30119 log.cc:1079] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/e6c1643565424e858f0818cf9f31c4e5/wal-000000039 (ops 189-192)
I20260812 06:19:51.393042 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: LogGCOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.002s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:19:51.393406 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5): perf score=2.188937
I20260812 06:19:51.405362 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.012s	user 0.005s	sys 0.005s Metrics: {"bytes_written":3200105,"delete_count":0,"lbm_write_time_us":4043,"lbm_writes_lt_1ms":81,"reinsert_count":0,"update_count":390}
I20260812 06:19:51.405947 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling UndoDeltaBlockGCOp(e6c1643565424e858f0818cf9f31c4e5): 473 bytes on disk
I20260812 06:19:51.406595 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: UndoDeltaBlockGCOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":71,"lbm_reads_lt_1ms":4}
I20260812 06:19:51.407130 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling MajorDeltaCompactionOp(e6c1643565424e858f0818cf9f31c4e5): perf score=1.000000
I20260812 06:19:51.578786 30002 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.128s	user 1.812s	sys 0.197s
I20260812 06:19:51.617615 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: MajorDeltaCompactionOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.210s	user 0.153s	sys 0.056s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979728,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":17722,"lbm_reads_lt_1ms":762,"lbm_write_time_us":37900,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":3500}
I20260812 06:19:51.618129 30189 maintenance_manager.cc:419] P b595af587a324ce88712468c5be35ced: Scheduling FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5): perf score=14.095187
I20260812 06:19:51.668512 30002 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.089s	user 0.004s	sys 0.000s
I20260812 06:19:51.669421 30002 tablet_server.cc:179] TabletServer@127.29.76.129:0 shutting down...
I20260812 06:19:51.708153 30119 maintenance_manager.cc:643] P b595af587a324ce88712468c5be35ced: FlushDeltaMemStoresOp(e6c1643565424e858f0818cf9f31c4e5) complete. Timing: real 0.090s	user 0.027s	sys 0.019s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":22279,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:51.708920 30002 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:51.709311 30002 tablet_replica.cc:333] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced: stopping tablet replica
I20260812 06:19:51.709564 30002 raft_consensus.cc:2243] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:51.709870 30002 raft_consensus.cc:2272] T e6c1643565424e858f0818cf9f31c4e5 P b595af587a324ce88712468c5be35ced [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:51.725167 30002 tablet_server.cc:196] TabletServer@127.29.76.129:0 shutdown complete.
I20260812 06:19:51.729982 30002 master.cc:562] Master@127.29.76.190:45277 shutting down...
I20260812 06:19:51.734091 30002 raft_consensus.cc:2243] T 00000000000000000000000000000000 P be9ff8b160ef4acf83ae04fef9a044d2 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:51.734318 30002 raft_consensus.cc:2272] T 00000000000000000000000000000000 P be9ff8b160ef4acf83ae04fef9a044d2 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:51.734401 30002 tablet_replica.cc:333] T 00000000000000000000000000000000 P be9ff8b160ef4acf83ae04fef9a044d2: stopping tablet replica
I20260812 06:19:51.747432 30002 master.cc:584] Master@127.29.76.190:45277 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5680 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:51.840304 30002 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.29.76.190:35737
I20260812 06:19:51.840758 30002 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:51.843087 30231 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:51.843230 30002 server_base.cc:1061] running on GCE node
W20260812 06:19:51.843201 30227 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:51.843151 30229 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:51.843588 30002 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:51.843632 30002 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:51.843647 30002 hybrid_clock.cc:648] HybridClock initialized: now 1786515591843647 us; error 0 us; skew 500 ppm
I20260812 06:19:51.844563 30002 webserver.cc:533] Webserver started at http://127.29.76.190:41669/ using document root <none> and password file <none>
I20260812 06:19:51.844749 30002 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:51.844805 30002 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:51.844910 30002 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:51.845399 30002 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586149177-30002-0/minicluster-data/master-0-root/instance:
uuid: "b08c76955c1f48d4bdd522f1e7178622"
format_stamp: "Formatted at 2026-08-12 06:19:51 on dist-test-slave-1zqn"
I20260812 06:19:51.847086 30002 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:51.848250 30237 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:51.848527 30002 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:51.848625 30002 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586149177-30002-0/minicluster-data/master-0-root
uuid: "b08c76955c1f48d4bdd522f1e7178622"
format_stamp: "Formatted at 2026-08-12 06:19:51 on dist-test-slave-1zqn"
I20260812 06:19:51.848722 30002 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586149177-30002-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586149177-30002-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586149177-30002-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:51.856361 30002 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:51.856806 30002 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:51.861266 30002 rpc_server.cc:307] RPC server started. Bound to: 127.29.76.190:35737
I20260812 06:19:51.865417 30296 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:51.867157 30295 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.29.76.190:35737 every 8 connection(s)
I20260812 06:19:51.879880 30296 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P b08c76955c1f48d4bdd522f1e7178622: Bootstrap starting.
I20260812 06:19:51.880894 30296 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P b08c76955c1f48d4bdd522f1e7178622: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:51.882189 30296 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P b08c76955c1f48d4bdd522f1e7178622: No bootstrap required, opened a new log
I20260812 06:19:51.882671 30296 raft_consensus.cc:359] T 00000000000000000000000000000000 P b08c76955c1f48d4bdd522f1e7178622 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b08c76955c1f48d4bdd522f1e7178622" member_type: VOTER }
I20260812 06:19:51.882772 30296 raft_consensus.cc:385] T 00000000000000000000000000000000 P b08c76955c1f48d4bdd522f1e7178622 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:51.882833 30296 raft_consensus.cc:740] T 00000000000000000000000000000000 P b08c76955c1f48d4bdd522f1e7178622 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: b08c76955c1f48d4bdd522f1e7178622, State: Initialized, Role: FOLLOWER
I20260812 06:19:51.883152 30296 consensus_queue.cc:260] T 00000000000000000000000000000000 P b08c76955c1f48d4bdd522f1e7178622 [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: "b08c76955c1f48d4bdd522f1e7178622" member_type: VOTER }
I20260812 06:19:51.883275 30296 raft_consensus.cc:399] T 00000000000000000000000000000000 P b08c76955c1f48d4bdd522f1e7178622 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:51.883352 30296 raft_consensus.cc:493] T 00000000000000000000000000000000 P b08c76955c1f48d4bdd522f1e7178622 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:51.883417 30296 raft_consensus.cc:3060] T 00000000000000000000000000000000 P b08c76955c1f48d4bdd522f1e7178622 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:51.884495 30296 raft_consensus.cc:515] T 00000000000000000000000000000000 P b08c76955c1f48d4bdd522f1e7178622 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b08c76955c1f48d4bdd522f1e7178622" member_type: VOTER }
I20260812 06:19:51.884634 30296 leader_election.cc:304] T 00000000000000000000000000000000 P b08c76955c1f48d4bdd522f1e7178622 [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: b08c76955c1f48d4bdd522f1e7178622; no voters: 
I20260812 06:19:51.884912 30296 leader_election.cc:290] T 00000000000000000000000000000000 P b08c76955c1f48d4bdd522f1e7178622 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:51.885103 30301 raft_consensus.cc:2804] T 00000000000000000000000000000000 P b08c76955c1f48d4bdd522f1e7178622 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:51.885363 30301 raft_consensus.cc:697] T 00000000000000000000000000000000 P b08c76955c1f48d4bdd522f1e7178622 [term 1 LEADER]: Becoming Leader. State: Replica: b08c76955c1f48d4bdd522f1e7178622, State: Running, Role: LEADER
I20260812 06:19:51.885571 30296 sys_catalog.cc:565] T 00000000000000000000000000000000 P b08c76955c1f48d4bdd522f1e7178622 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:51.885517 30301 consensus_queue.cc:237] T 00000000000000000000000000000000 P b08c76955c1f48d4bdd522f1e7178622 [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: "b08c76955c1f48d4bdd522f1e7178622" member_type: VOTER }
I20260812 06:19:51.886108 30303 sys_catalog.cc:455] T 00000000000000000000000000000000 P b08c76955c1f48d4bdd522f1e7178622 [sys.catalog]: SysCatalogTable state changed. Reason: New leader b08c76955c1f48d4bdd522f1e7178622. Latest consensus state: current_term: 1 leader_uuid: "b08c76955c1f48d4bdd522f1e7178622" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b08c76955c1f48d4bdd522f1e7178622" member_type: VOTER } }
I20260812 06:19:51.886181 30303 sys_catalog.cc:458] T 00000000000000000000000000000000 P b08c76955c1f48d4bdd522f1e7178622 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:51.886059 30302 sys_catalog.cc:455] T 00000000000000000000000000000000 P b08c76955c1f48d4bdd522f1e7178622 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "b08c76955c1f48d4bdd522f1e7178622" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b08c76955c1f48d4bdd522f1e7178622" member_type: VOTER } }
I20260812 06:19:51.886318 30302 sys_catalog.cc:458] T 00000000000000000000000000000000 P b08c76955c1f48d4bdd522f1e7178622 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:51.886876 30306 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:51.887581 30306 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:51.887848 30002 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:51.889874 30306 catalog_manager.cc:1383] Generated new cluster ID: 2dcda620279346a4a924117c1bd6fc33
I20260812 06:19:51.889951 30306 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:51.910652 30306 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:51.911345 30306 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:51.921307 30306 catalog_manager.cc:6092] T 00000000000000000000000000000000 P b08c76955c1f48d4bdd522f1e7178622: Generated new TSK 0
I20260812 06:19:51.921531 30306 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:51.952801 30002 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:51.955406 30323 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:51.955390 30002 server_base.cc:1061] running on GCE node
W20260812 06:19:51.955391 30325 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:51.955561 30322 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:51.955781 30002 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:51.955826 30002 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:51.955842 30002 hybrid_clock.cc:648] HybridClock initialized: now 1786515591955842 us; error 0 us; skew 500 ppm
I20260812 06:19:51.956831 30002 webserver.cc:533] Webserver started at http://127.29.76.129:37667/ using document root <none> and password file <none>
I20260812 06:19:51.957067 30002 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:51.957206 30002 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:51.957271 30002 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:51.957698 30002 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586149177-30002-0/minicluster-data/ts-0-root/instance:
uuid: "74e1bc64a9904cf4b3f5f8ccef471c9a"
format_stamp: "Formatted at 2026-08-12 06:19:51 on dist-test-slave-1zqn"
I20260812 06:19:51.959476 30002 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:19:51.960784 30330 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:51.961120 30002 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.000s
I20260812 06:19:51.961192 30002 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586149177-30002-0/minicluster-data/ts-0-root
uuid: "74e1bc64a9904cf4b3f5f8ccef471c9a"
format_stamp: "Formatted at 2026-08-12 06:19:51 on dist-test-slave-1zqn"
I20260812 06:19:51.961288 30002 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586149177-30002-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586149177-30002-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586149177-30002-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:51.977579 30002 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:51.978040 30002 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:51.978384 30002 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:51.978907 30002 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:51.978974 30002 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:51.979063 30002 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:51.979112 30002 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:51.983855 30002 rpc_server.cc:307] RPC server started. Bound to: 127.29.76.129:45255
I20260812 06:19:51.983950 30406 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.29.76.129:45255 every 8 connection(s)
I20260812 06:19:51.990183 30407 heartbeater.cc:344] Connected to a master server at 127.29.76.190:35737
I20260812 06:19:51.990338 30407 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:51.990653 30407 heartbeater.cc:507] Master 127.29.76.190:35737 requested a full tablet report, sending...
I20260812 06:19:51.991500 30257 ts_manager.cc:194] Registered new tserver with Master: 74e1bc64a9904cf4b3f5f8ccef471c9a (127.29.76.129:45255)
I20260812 06:19:51.992429 30002 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.008079818s
I20260812 06:19:51.992444 30257 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:51516
I20260812 06:19:52.001263 30257 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:51518:
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:52.011745 30365 tablet_service.cc:1511] Processing CreateTablet for tablet 086d5f5375cb4c4494155904717ee7d7 (DEFAULT_TABLE table=heavy-update-compaction-test [id=4dc783376f0543db928c6c44286aff6f]), partition=
I20260812 06:19:52.012041 30365 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 086d5f5375cb4c4494155904717ee7d7. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:52.014384 30419 tablet_bootstrap.cc:492] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a: Bootstrap starting.
I20260812 06:19:52.015403 30419 tablet_bootstrap.cc:654] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:52.016872 30419 tablet_bootstrap.cc:492] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a: No bootstrap required, opened a new log
I20260812 06:19:52.017063 30419 ts_tablet_manager.cc:1403] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:19:52.017652 30419 raft_consensus.cc:359] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "74e1bc64a9904cf4b3f5f8ccef471c9a" member_type: VOTER last_known_addr { host: "127.29.76.129" port: 45255 } }
I20260812 06:19:52.017764 30419 raft_consensus.cc:385] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:52.017812 30419 raft_consensus.cc:740] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 74e1bc64a9904cf4b3f5f8ccef471c9a, State: Initialized, Role: FOLLOWER
I20260812 06:19:52.017957 30419 consensus_queue.cc:260] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a [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: "74e1bc64a9904cf4b3f5f8ccef471c9a" member_type: VOTER last_known_addr { host: "127.29.76.129" port: 45255 } }
I20260812 06:19:52.018066 30419 raft_consensus.cc:399] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:52.018110 30419 raft_consensus.cc:493] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:52.018167 30419 raft_consensus.cc:3060] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:52.018960 30419 raft_consensus.cc:515] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "74e1bc64a9904cf4b3f5f8ccef471c9a" member_type: VOTER last_known_addr { host: "127.29.76.129" port: 45255 } }
I20260812 06:19:52.019129 30419 leader_election.cc:304] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a [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: 74e1bc64a9904cf4b3f5f8ccef471c9a; no voters: 
I20260812 06:19:52.019359 30419 leader_election.cc:290] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:52.019555 30421 raft_consensus.cc:2804] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:52.019788 30407 heartbeater.cc:499] Master 127.29.76.190:35737 was elected leader, sending a full tablet report...
I20260812 06:19:52.019786 30419 ts_tablet_manager.cc:1434] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:19:52.019824 30421 raft_consensus.cc:697] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a [term 1 LEADER]: Becoming Leader. State: Replica: 74e1bc64a9904cf4b3f5f8ccef471c9a, State: Running, Role: LEADER
I20260812 06:19:52.020181 30421 consensus_queue.cc:237] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a [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: "74e1bc64a9904cf4b3f5f8ccef471c9a" member_type: VOTER last_known_addr { host: "127.29.76.129" port: 45255 } }
I20260812 06:19:52.021795 30256 catalog_manager.cc:5719] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a reported cstate change: term changed from 0 to 1, leader changed from <none> to 74e1bc64a9904cf4b3f5f8ccef471c9a (127.29.76.129). New cstate: current_term: 1 leader_uuid: "74e1bc64a9904cf4b3f5f8ccef471c9a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "74e1bc64a9904cf4b3f5f8ccef471c9a" member_type: VOTER last_known_addr { host: "127.29.76.129" port: 45255 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:52.088861 30002 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.061s	user 0.023s	sys 0.004s
I20260812 06:19:52.234915 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling FlushMRSOp(086d5f5375cb4c4494155904717ee7d7): perf score=15.086190
I20260812 06:19:52.378656 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: FlushMRSOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.143s	user 0.105s	sys 0.032s Metrics: {"bytes_written":11897249,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":75,"dirs.run_cpu_time_us":254,"dirs.run_wall_time_us":1401,"drs_written":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4,"lbm_write_time_us":36217,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1450}
I20260812 06:19:52.379333 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling LogGCOp(086d5f5375cb4c4494155904717ee7d7): free 20743880 bytes of WAL
I20260812 06:19:52.379607 30336 log_reader.cc:385] T 086d5f5375cb4c4494155904717ee7d7: removed 2 log segments from log reader
I20260812 06:19:52.379655 30336 log.cc:1079] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/086d5f5375cb4c4494155904717ee7d7/wal-000000001 (ops 1-6)
I20260812 06:19:52.379689 30336 log.cc:1079] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/086d5f5375cb4c4494155904717ee7d7/wal-000000002 (ops 7-11)
I20260812 06:19:52.384294 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: LogGCOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.005s	user 0.000s	sys 0.005s Metrics: {}
I20260812 06:19:52.384714 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling UndoDeltaBlockGCOp(086d5f5375cb4c4494155904717ee7d7): 12719217 bytes on disk
I20260812 06:19:52.385200 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: UndoDeltaBlockGCOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4}
I20260812 06:19:52.385643 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7): perf score=2.188937
I20260812 06:19:52.402695 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.017s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6504,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:52.403184 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling MajorDeltaCompactionOp(086d5f5375cb4c4494155904717ee7d7): perf score=1.000000
I20260812 06:19:52.540611 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: MajorDeltaCompactionOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.137s	user 0.122s	sys 0.015s Metrics: {"cfile_cache_miss":422,"cfile_cache_miss_bytes":20262036,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":464,"lbm_read_time_us":9429,"lbm_reads_lt_1ms":450,"lbm_write_time_us":24753,"lbm_writes_lt_1ms":433,"peak_mem_usage":49238594,"reinsert_count":0,"spinlock_wait_cycles":3200,"thread_start_us":345,"threads_started":5,"update_count":1950}
I20260812 06:19:52.541244 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7): perf score=10.126437
I20260812 06:19:52.579905 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.038s	user 0.018s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15906,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:52.580585 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7): perf score=2.188937
I20260812 06:19:52.597339 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.017s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6755,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:52.597873 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling MajorDeltaCompactionOp(086d5f5375cb4c4494155904717ee7d7): perf score=1.000000
I20260812 06:19:52.743258 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: MajorDeltaCompactionOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.145s	user 0.104s	sys 0.041s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":309,"lbm_read_time_us":8713,"lbm_reads_lt_1ms":468,"lbm_write_time_us":30599,"lbm_writes_lt_1ms":443,"mutex_wait_us":21,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10112,"update_count":2000}
I20260812 06:19:52.744005 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7): perf score=10.126437
I20260812 06:19:52.790843 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.047s	user 0.015s	sys 0.028s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14640,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:52.791508 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7): perf score=2.188937
I20260812 06:19:52.810011 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.018s	user 0.004s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6772,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:52.810773 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling MajorDeltaCompactionOp(086d5f5375cb4c4494155904717ee7d7): perf score=1.000000
I20260812 06:19:52.983070 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: MajorDeltaCompactionOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.172s	user 0.106s	sys 0.060s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":834,"lbm_read_time_us":11753,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26079,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":110848,"update_count":2000}
I20260812 06:19:52.983716 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7): perf score=14.095187
I20260812 06:19:53.038822 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.055s	user 0.028s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24157,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:53.039347 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7): perf score=2.188937
I20260812 06:19:53.051069 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4166,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:53.051523 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling MajorDeltaCompactionOp(086d5f5375cb4c4494155904717ee7d7): perf score=1.000000
I20260812 06:19:53.230962 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: MajorDeltaCompactionOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.179s	user 0.132s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":195,"lbm_read_time_us":11856,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33547,"lbm_writes_lt_1ms":543,"mutex_wait_us":47,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13696,"update_count":2500}
I20260812 06:19:53.231642 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7): perf score=14.095187
I20260812 06:19:53.279847 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.048s	user 0.034s	sys 0.011s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":21077,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:53.280421 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7): perf score=2.188937
I20260812 06:19:53.292906 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.012s	user 0.003s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4678,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:53.293483 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling MajorDeltaCompactionOp(086d5f5375cb4c4494155904717ee7d7): perf score=1.000000
I20260812 06:19:53.444557 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: MajorDeltaCompactionOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.151s	user 0.114s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774692,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":2782,"lbm_read_time_us":12763,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29953,"lbm_writes_lt_1ms":543,"mutex_wait_us":848,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15488,"update_count":2500}
I20260812 06:19:53.445456 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7): perf score=10.126437
I20260812 06:19:53.481236 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.034s	user 0.025s	sys 0.007s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14341,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:53.481715 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7): perf score=2.188937
I20260812 06:19:53.498770 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.017s	user 0.016s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6355,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:53.499282 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling MajorDeltaCompactionOp(086d5f5375cb4c4494155904717ee7d7): perf score=1.000000
I20260812 06:19:53.630363 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: MajorDeltaCompactionOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.131s	user 0.102s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":214,"lbm_read_time_us":10045,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24964,"lbm_writes_lt_1ms":443,"mutex_wait_us":63,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":20480,"update_count":2000}
I20260812 06:19:53.631157 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7): perf score=10.126437
I20260812 06:19:53.687325 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.056s	user 0.026s	sys 0.022s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17803,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:53.687950 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7): perf score=2.188937
I20260812 06:19:53.699314 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4384,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:53.699766 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling FlushMRSOp(086d5f5375cb4c4494155904717ee7d7): perf score=1.000000
I20260812 06:19:53.731511 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: FlushMRSOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.032s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":99,"dirs.run_cpu_time_us":235,"dirs.run_wall_time_us":1478,"drs_written":1,"lbm_read_time_us":116,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1471,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:53.732303 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling MajorDeltaCompactionOp(086d5f5375cb4c4494155904717ee7d7): perf score=1.000000
I20260812 06:19:53.903728 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: MajorDeltaCompactionOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.171s	user 0.098s	sys 0.061s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":358,"lbm_read_time_us":10704,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26036,"lbm_writes_lt_1ms":443,"mutex_wait_us":3,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3456,"update_count":2000}
I20260812 06:19:53.904328 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling LogGCOp(086d5f5375cb4c4494155904717ee7d7): free 120553329 bytes of WAL
I20260812 06:19:53.904603 30336 log_reader.cc:385] T 086d5f5375cb4c4494155904717ee7d7: removed 12 log segments from log reader
I20260812 06:19:53.904661 30336 log.cc:1079] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/086d5f5375cb4c4494155904717ee7d7/wal-000000003 (ops 12-16)
I20260812 06:19:53.904701 30336 log.cc:1079] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/086d5f5375cb4c4494155904717ee7d7/wal-000000004 (ops 17-21)
I20260812 06:19:53.904737 30336 log.cc:1079] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/086d5f5375cb4c4494155904717ee7d7/wal-000000005 (ops 22-26)
I20260812 06:19:53.904817 30336 log.cc:1079] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/086d5f5375cb4c4494155904717ee7d7/wal-000000006 (ops 27-30)
I20260812 06:19:53.904853 30336 log.cc:1079] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/086d5f5375cb4c4494155904717ee7d7/wal-000000007 (ops 31-35)
I20260812 06:19:53.904915 30336 log.cc:1079] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/086d5f5375cb4c4494155904717ee7d7/wal-000000008 (ops 36-40)
I20260812 06:19:53.904955 30336 log.cc:1079] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/086d5f5375cb4c4494155904717ee7d7/wal-000000009 (ops 41-45)
I20260812 06:19:53.904987 30336 log.cc:1079] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/086d5f5375cb4c4494155904717ee7d7/wal-000000010 (ops 46-50)
I20260812 06:19:53.905017 30336 log.cc:1079] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/086d5f5375cb4c4494155904717ee7d7/wal-000000011 (ops 51-55)
I20260812 06:19:53.905066 30336 log.cc:1079] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/086d5f5375cb4c4494155904717ee7d7/wal-000000012 (ops 56-60)
I20260812 06:19:53.905103 30336 log.cc:1079] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/086d5f5375cb4c4494155904717ee7d7/wal-000000013 (ops 61-64)
I20260812 06:19:53.905159 30336 log.cc:1079] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/086d5f5375cb4c4494155904717ee7d7/wal-000000014 (ops 65-69)
I20260812 06:19:53.938779 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: LogGCOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.034s	user 0.003s	sys 0.028s Metrics: {}
I20260812 06:19:53.939237 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7): perf score=14.095187
I20260812 06:19:53.992209 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.053s	user 0.049s	sys 0.004s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23314,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:53.992774 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling UndoDeltaBlockGCOp(086d5f5375cb4c4494155904717ee7d7): 462 bytes on disk
I20260812 06:19:53.993391 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: UndoDeltaBlockGCOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":104,"lbm_reads_lt_1ms":4}
I20260812 06:19:53.993922 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7): perf score=2.188937
I20260812 06:19:54.032387 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.038s	user 0.017s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6418,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:54.032939 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7): perf score=2.188937
I20260812 06:19:54.045564 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.012s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5028,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:54.046128 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling MajorDeltaCompactionOp(086d5f5375cb4c4494155904717ee7d7): perf score=1.000000
I20260812 06:19:54.261838 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: MajorDeltaCompactionOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.215s	user 0.140s	sys 0.074s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877219,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":255,"lbm_read_time_us":16253,"lbm_reads_lt_1ms":673,"lbm_write_time_us":33735,"lbm_writes_lt_1ms":643,"mutex_wait_us":71,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":3000}
I20260812 06:19:54.262651 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7): perf score=14.095187
I20260812 06:19:54.325121 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.062s	user 0.034s	sys 0.028s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23157,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:54.325764 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7): perf score=2.188937
I20260812 06:19:54.337057 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4330,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:54.340140 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling MajorDeltaCompactionOp(086d5f5375cb4c4494155904717ee7d7): perf score=1.000000
I20260812 06:19:54.525182 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: MajorDeltaCompactionOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.185s	user 0.109s	sys 0.073s 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":72,"lbm_read_time_us":13008,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30613,"lbm_writes_lt_1ms":543,"mutex_wait_us":45,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:19:54.525890 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7): perf score=11.118625
I20260812 06:19:54.566251 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.040s	user 0.027s	sys 0.011s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16969,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:54.567057 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7): perf score=2.188937
I20260812 06:19:54.582226 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5530,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:54.582854 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling MajorDeltaCompactionOp(086d5f5375cb4c4494155904717ee7d7): perf score=1.000000
I20260812 06:19:54.733054 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: MajorDeltaCompactionOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.150s	user 0.111s	sys 0.039s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":490,"lbm_read_time_us":8531,"lbm_reads_lt_1ms":468,"lbm_write_time_us":28392,"lbm_writes_lt_1ms":443,"mutex_wait_us":306,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4992,"update_count":2000}
I20260812 06:19:54.734059 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7): perf score=10.126437
I20260812 06:19:54.770638 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.036s	user 0.016s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14497,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:54.771243 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7): perf score=2.188937
I20260812 06:19:54.782202 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4172,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:54.782963 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling MajorDeltaCompactionOp(086d5f5375cb4c4494155904717ee7d7): perf score=1.000000
I20260812 06:19:54.927829 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: MajorDeltaCompactionOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.145s	user 0.116s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1281,"lbm_read_time_us":10994,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27128,"lbm_writes_lt_1ms":443,"mutex_wait_us":41,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":24960,"update_count":2000}
I20260812 06:19:54.928807 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7): perf score=10.126437
I20260812 06:19:54.976009 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.047s	user 0.013s	sys 0.027s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":18345,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:54.976577 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7): perf score=2.188937
I20260812 06:19:54.988441 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4243,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:54.989174 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling MajorDeltaCompactionOp(086d5f5375cb4c4494155904717ee7d7): perf score=1.000000
I20260812 06:19:55.121807 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: MajorDeltaCompactionOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.132s	user 0.108s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":697,"lbm_read_time_us":8251,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24506,"lbm_writes_lt_1ms":443,"mutex_wait_us":285,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":140928,"update_count":2000}
I20260812 06:19:55.122324 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7): perf score=10.126437
I20260812 06:19:55.164734 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.042s	user 0.014s	sys 0.027s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":13526,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":1500}
I20260812 06:19:55.165356 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7): perf score=2.188937
I20260812 06:19:55.176196 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4194,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.176653 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling MajorDeltaCompactionOp(086d5f5375cb4c4494155904717ee7d7): perf score=1.000000
I20260812 06:19:55.335883 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: MajorDeltaCompactionOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.159s	user 0.115s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":230,"lbm_read_time_us":11552,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25055,"lbm_writes_lt_1ms":443,"mutex_wait_us":48,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:55.336621 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7): perf score=10.126437
I20260812 06:19:55.380671 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.044s	user 0.036s	sys 0.007s Metrics: {"bytes_written":12307494,"delete_count":0,"lbm_write_time_us":19106,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:55.381235 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7): perf score=2.188937
I20260812 06:19:55.392263 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4100,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.392765 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling FlushMRSOp(086d5f5375cb4c4494155904717ee7d7): perf score=1.000000
I20260812 06:19:55.427335 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: FlushMRSOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.034s	user 0.029s	sys 0.004s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":66,"dirs.run_cpu_time_us":167,"dirs.run_wall_time_us":1362,"drs_written":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2259,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:55.428159 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling LogGCOp(086d5f5375cb4c4494155904717ee7d7): free 124257299 bytes of WAL
I20260812 06:19:55.428435 30336 log_reader.cc:385] T 086d5f5375cb4c4494155904717ee7d7: removed 12 log segments from log reader
I20260812 06:19:55.428503 30336 log.cc:1079] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/086d5f5375cb4c4494155904717ee7d7/wal-000000015 (ops 70-74)
I20260812 06:19:55.428544 30336 log.cc:1079] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/086d5f5375cb4c4494155904717ee7d7/wal-000000016 (ops 75-79)
I20260812 06:19:55.428570 30336 log.cc:1079] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/086d5f5375cb4c4494155904717ee7d7/wal-000000017 (ops 80-84)
I20260812 06:19:55.428592 30336 log.cc:1079] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/086d5f5375cb4c4494155904717ee7d7/wal-000000018 (ops 85-89)
I20260812 06:19:55.428632 30336 log.cc:1079] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/086d5f5375cb4c4494155904717ee7d7/wal-000000019 (ops 90-94)
I20260812 06:19:55.428656 30336 log.cc:1079] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/086d5f5375cb4c4494155904717ee7d7/wal-000000020 (ops 95-99)
I20260812 06:19:55.428690 30336 log.cc:1079] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/086d5f5375cb4c4494155904717ee7d7/wal-000000021 (ops 100-104)
I20260812 06:19:55.428722 30336 log.cc:1079] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/086d5f5375cb4c4494155904717ee7d7/wal-000000022 (ops 105-108)
I20260812 06:19:55.428752 30336 log.cc:1079] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/086d5f5375cb4c4494155904717ee7d7/wal-000000023 (ops 109-113)
I20260812 06:19:55.428781 30336 log.cc:1079] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/086d5f5375cb4c4494155904717ee7d7/wal-000000024 (ops 114-118)
I20260812 06:19:55.428808 30336 log.cc:1079] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/086d5f5375cb4c4494155904717ee7d7/wal-000000025 (ops 119-123)
I20260812 06:19:55.428838 30336 log.cc:1079] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/086d5f5375cb4c4494155904717ee7d7/wal-000000026 (ops 124-128)
I20260812 06:19:55.459438 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: LogGCOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.031s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:19:55.459937 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7): perf score=3.181125
I20260812 06:19:55.474984 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.015s	user 0.002s	sys 0.009s Metrics: {"bytes_written":4430851,"delete_count":0,"lbm_write_time_us":4959,"lbm_writes_lt_1ms":111,"reinsert_count":0,"update_count":540}
I20260812 06:19:55.475452 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7): perf score=2.188937
I20260812 06:19:55.496258 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.021s	user 0.014s	sys 0.007s Metrics: {"bytes_written":3774459,"delete_count":0,"lbm_write_time_us":3832,"lbm_writes_lt_1ms":95,"reinsert_count":0,"update_count":460}
I20260812 06:19:55.496795 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling UndoDeltaBlockGCOp(086d5f5375cb4c4494155904717ee7d7): 483 bytes on disk
I20260812 06:19:55.497291 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: UndoDeltaBlockGCOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4}
I20260812 06:19:55.497854 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling MajorDeltaCompactionOp(086d5f5375cb4c4494155904717ee7d7): perf score=1.000000
I20260812 06:19:55.712001 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: MajorDeltaCompactionOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.214s	user 0.170s	sys 0.041s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877335,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":470,"lbm_read_time_us":14688,"lbm_reads_lt_1ms":674,"lbm_write_time_us":36796,"lbm_writes_lt_1ms":643,"mutex_wait_us":67,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":14720,"thread_start_us":109,"threads_started":1,"update_count":3000}
I20260812 06:19:55.712594 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7): perf score=14.095187
I20260812 06:19:55.786780 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.074s	user 0.032s	sys 0.031s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24202,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:55.787331 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7): perf score=2.188937
I20260812 06:19:55.798712 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4359,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.799270 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling MajorDeltaCompactionOp(086d5f5375cb4c4494155904717ee7d7): perf score=1.000000
I20260812 06:19:55.984438 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: MajorDeltaCompactionOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.185s	user 0.125s	sys 0.059s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":175,"lbm_read_time_us":13072,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29023,"lbm_writes_lt_1ms":543,"mutex_wait_us":51,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11264,"update_count":2500}
I20260812 06:19:55.984984 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7): perf score=10.126437
I20260812 06:19:56.023213 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.038s	user 0.002s	sys 0.033s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16592,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:56.023912 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7): perf score=2.188937
I20260812 06:19:56.040266 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.016s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6191,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.040805 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling MajorDeltaCompactionOp(086d5f5375cb4c4494155904717ee7d7): perf score=1.000000
I20260812 06:19:56.171828 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: MajorDeltaCompactionOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.131s	user 0.094s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":463,"lbm_read_time_us":8642,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25299,"lbm_writes_lt_1ms":443,"mutex_wait_us":73,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5504,"update_count":2000}
I20260812 06:19:56.172593 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7): perf score=10.126437
I20260812 06:19:56.227239 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.054s	user 0.027s	sys 0.012s Metrics: {"bytes_written":12307495,"delete_count":0,"lbm_write_time_us":18374,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:56.227798 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7): perf score=2.188937
I20260812 06:19:56.241886 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.014s	user 0.009s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4648,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.242632 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling MajorDeltaCompactionOp(086d5f5375cb4c4494155904717ee7d7): perf score=1.000000
I20260812 06:19:56.374480 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: MajorDeltaCompactionOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.132s	user 0.111s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672282,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":980,"lbm_read_time_us":9375,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27106,"lbm_writes_lt_1ms":443,"mutex_wait_us":332,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":61184,"update_count":2000}
I20260812 06:19:56.375028 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7): perf score=10.126437
I20260812 06:19:56.419389 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.044s	user 0.023s	sys 0.015s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":19217,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:56.419931 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7): perf score=2.188937
I20260812 06:19:56.430487 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3958,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.431231 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling MajorDeltaCompactionOp(086d5f5375cb4c4494155904717ee7d7): perf score=1.000000
I20260812 06:19:56.553485 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: MajorDeltaCompactionOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.122s	user 0.091s	sys 0.030s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":275,"lbm_read_time_us":8625,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22490,"lbm_writes_lt_1ms":443,"mutex_wait_us":48,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":24960,"update_count":2000}
I20260812 06:19:56.554262 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7): perf score=10.126437
I20260812 06:19:56.607373 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.053s	user 0.034s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16612,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:56.608229 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7): perf score=2.188937
I20260812 06:19:56.620788 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.012s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4795,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.621322 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling MajorDeltaCompactionOp(086d5f5375cb4c4494155904717ee7d7): perf score=1.000000
I20260812 06:19:56.797820 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: MajorDeltaCompactionOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.176s	user 0.130s	sys 0.046s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":167,"lbm_read_time_us":13690,"lbm_reads_lt_1ms":472,"lbm_write_time_us":32450,"lbm_writes_lt_1ms":443,"mutex_wait_us":55,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11392,"update_count":2000}
I20260812 06:19:56.798718 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7): perf score=11.118625
I20260812 06:19:56.832134 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.033s	user 0.013s	sys 0.020s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14602,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:56.832695 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7): perf score=2.188937
I20260812 06:19:56.852622 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.020s	user 0.002s	sys 0.012s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5674,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:56.853147 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling FlushMRSOp(086d5f5375cb4c4494155904717ee7d7): perf score=1.000000
I20260812 06:19:56.911279 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: FlushMRSOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.058s	user 0.033s	sys 0.004s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":75,"dirs.run_cpu_time_us":215,"dirs.run_wall_time_us":1521,"drs_written":1,"lbm_read_time_us":99,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1866,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:56.912042 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling LogGCOp(086d5f5375cb4c4494155904717ee7d7): free 112239558 bytes of WAL
I20260812 06:19:56.912362 30336 log_reader.cc:385] T 086d5f5375cb4c4494155904717ee7d7: removed 11 log segments from log reader
I20260812 06:19:56.912411 30336 log.cc:1079] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/086d5f5375cb4c4494155904717ee7d7/wal-000000027 (ops 129-133)
I20260812 06:19:56.912444 30336 log.cc:1079] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/086d5f5375cb4c4494155904717ee7d7/wal-000000028 (ops 134-138)
I20260812 06:19:56.912518 30336 log.cc:1079] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/086d5f5375cb4c4494155904717ee7d7/wal-000000029 (ops 139-143)
I20260812 06:19:56.912559 30336 log.cc:1079] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/086d5f5375cb4c4494155904717ee7d7/wal-000000030 (ops 144-148)
I20260812 06:19:56.912611 30336 log.cc:1079] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/086d5f5375cb4c4494155904717ee7d7/wal-000000031 (ops 149-153)
I20260812 06:19:56.912683 30336 log.cc:1079] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/086d5f5375cb4c4494155904717ee7d7/wal-000000032 (ops 154-158)
I20260812 06:19:56.912744 30336 log.cc:1079] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/086d5f5375cb4c4494155904717ee7d7/wal-000000033 (ops 159-163)
I20260812 06:19:56.912791 30336 log.cc:1079] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/086d5f5375cb4c4494155904717ee7d7/wal-000000034 (ops 164-168)
I20260812 06:19:56.912835 30336 log.cc:1079] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/086d5f5375cb4c4494155904717ee7d7/wal-000000035 (ops 169-173)
I20260812 06:19:56.912880 30336 log.cc:1079] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/086d5f5375cb4c4494155904717ee7d7/wal-000000036 (ops 174-178)
I20260812 06:19:56.912925 30336 log.cc:1079] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/086d5f5375cb4c4494155904717ee7d7/wal-000000037 (ops 179-182)
I20260812 06:19:56.942726 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: LogGCOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.030s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:19:56.946280 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling UndoDeltaBlockGCOp(086d5f5375cb4c4494155904717ee7d7): 447 bytes on disk
I20260812 06:19:56.946874 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: UndoDeltaBlockGCOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4}
I20260812 06:19:56.947638 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7): perf score=6.157687
I20260812 06:19:56.968693 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.021s	user 0.005s	sys 0.015s Metrics: {"bytes_written":8205088,"delete_count":0,"lbm_write_time_us":8994,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:56.969234 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling LogGCOp(086d5f5375cb4c4494155904717ee7d7): free 8767140 bytes of WAL
I20260812 06:19:56.969498 30336 log_reader.cc:385] T 086d5f5375cb4c4494155904717ee7d7: removed 1 log segments from log reader
I20260812 06:19:56.969561 30336 log.cc:1079] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a: Deleting log segment in path: /tmp/dist-test-taskfZrJVF/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515586149177-30002-0/minicluster-data/ts-0-root/wals/086d5f5375cb4c4494155904717ee7d7/wal-000000038 (ops 183-187)
I20260812 06:19:56.971801 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: LogGCOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:19:56.972255 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7): perf score=2.188937
I20260812 06:19:56.982744 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4115,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.983220 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling MajorDeltaCompactionOp(086d5f5375cb4c4494155904717ee7d7): perf score=1.000000
I20260812 06:19:57.218887 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: MajorDeltaCompactionOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.235s	user 0.148s	sys 0.084s 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":1480,"lbm_read_time_us":16929,"lbm_reads_lt_1ms":774,"lbm_write_time_us":40479,"lbm_writes_lt_1ms":743,"mutex_wait_us":346,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":4352,"thread_start_us":84,"threads_started":1,"update_count":3500}
I20260812 06:19:57.219700 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7): perf score=16.079562
I20260812 06:19:57.267925 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.048s	user 0.011s	sys 0.033s Metrics: {"bytes_written":17804727,"delete_count":0,"lbm_write_time_us":21838,"lbm_writes_lt_1ms":437,"reinsert_count":0,"update_count":2170}
I20260812 06:19:57.268710 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7): perf score=1.196750
I20260812 06:19:57.290524 30002 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.202s	user 1.884s	sys 0.219s
I20260812 06:19:57.291823 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.023s	user 0.008s	sys 0.000s Metrics: {"bytes_written":2707805,"delete_count":0,"lbm_write_time_us":3293,"lbm_writes_lt_1ms":69,"reinsert_count":0,"update_count":330}
I20260812 06:19:57.292410 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7): perf score=2.188937
I20260812 06:19:57.303258 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: FlushDeltaMemStoresOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.010s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4246,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.303759 30408 maintenance_manager.cc:419] P 74e1bc64a9904cf4b3f5f8ccef471c9a: Scheduling MajorDeltaCompactionOp(086d5f5375cb4c4494155904717ee7d7): perf score=1.000000
I20260812 06:19:57.360880 30002 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.070s	user 0.002s	sys 0.000s
I20260812 06:19:57.361426 30002 tablet_server.cc:179] TabletServer@127.29.76.129:0 shutting down...
I20260812 06:19:57.454849 30336 maintenance_manager.cc:643] P 74e1bc64a9904cf4b3f5f8ccef471c9a: MajorDeltaCompactionOp(086d5f5375cb4c4494155904717ee7d7) complete. Timing: real 0.151s	user 0.083s	sys 0.068s Metrics: {"cfile_cache_hit":250,"cfile_cache_hit_bytes":10177498,"cfile_cache_miss":383,"cfile_cache_miss_bytes":18699693,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":753,"lbm_read_time_us":8599,"lbm_reads_lt_1ms":415,"lbm_write_time_us":29504,"lbm_writes_lt_1ms":643,"mutex_wait_us":51,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":188416,"update_count":3000}
I20260812 06:19:57.455605 30002 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:57.455852 30002 tablet_replica.cc:333] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a: stopping tablet replica
I20260812 06:19:57.456024 30002 raft_consensus.cc:2243] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:57.456229 30002 raft_consensus.cc:2272] T 086d5f5375cb4c4494155904717ee7d7 P 74e1bc64a9904cf4b3f5f8ccef471c9a [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:57.470500 30002 tablet_server.cc:196] TabletServer@127.29.76.129:0 shutdown complete.
I20260812 06:19:57.507926 30002 master.cc:562] Master@127.29.76.190:35737 shutting down...
I20260812 06:19:57.511652 30002 raft_consensus.cc:2243] T 00000000000000000000000000000000 P b08c76955c1f48d4bdd522f1e7178622 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:57.511876 30002 raft_consensus.cc:2272] T 00000000000000000000000000000000 P b08c76955c1f48d4bdd522f1e7178622 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:57.511967 30002 tablet_replica.cc:333] T 00000000000000000000000000000000 P b08c76955c1f48d4bdd522f1e7178622: stopping tablet replica
I20260812 06:19:57.524626 30002 master.cc:584] Master@127.29.76.190:35737 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5776 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11457 ms total)

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