[==========] 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:20:16.677000 30017 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.29.80.126:45561
I20260812 06:20:16.678025 30017 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:20:16.678580 30017 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:16.684461 30037 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:20:16.684547 30017 server_base.cc:1061] running on GCE node
W20260812 06:20:16.684480 30034 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:16.684732 30032 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:20:16.685235 30017 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:16.685333 30017 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:20:16.685375 30017 hybrid_clock.cc:648] HybridClock initialized: now 1786515616685372 us; error 0 us; skew 500 ppm
I20260812 06:20:16.687073 30017 webserver.cc:533] Webserver started at http://127.29.80.126:34433/ using document root <none> and password file <none>
I20260812 06:20:16.687573 30017 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:16.687639 30017 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:16.687849 30017 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:16.689492 30017 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616667027-30017-0/minicluster-data/master-0-root/instance:
uuid: "4bbfcb1513d4431383eb373d7557ebac"
format_stamp: "Formatted at 2026-08-12 06:20:16 on dist-test-slave-42z9"
I20260812 06:20:16.692682 30017 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.000s	sys 0.002s
I20260812 06:20:16.694523 30046 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:20:16.695425 30017 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:20:16.695537 30017 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616667027-30017-0/minicluster-data/master-0-root
uuid: "4bbfcb1513d4431383eb373d7557ebac"
format_stamp: "Formatted at 2026-08-12 06:20:16 on dist-test-slave-42z9"
I20260812 06:20:16.695640 30017 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616667027-30017-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616667027-30017-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616667027-30017-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:20:16.708973 30017 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:16.709514 30017 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:20:16.709659 30017 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:16.716427 30017 rpc_server.cc:307] RPC server started. Bound to: 127.29.80.126:45561
I20260812 06:20:16.716450 30133 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.29.80.126:45561 every 8 connection(s)
I20260812 06:20:16.718451 30134 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:20:16.723562 30134 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 4bbfcb1513d4431383eb373d7557ebac: Bootstrap starting.
I20260812 06:20:16.725713 30134 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 4bbfcb1513d4431383eb373d7557ebac: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:16.726516 30134 log.cc:826] T 00000000000000000000000000000000 P 4bbfcb1513d4431383eb373d7557ebac: Log is configured to *not* fsync() on all Append() calls
I20260812 06:20:16.727962 30134 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 4bbfcb1513d4431383eb373d7557ebac: No bootstrap required, opened a new log
I20260812 06:20:16.730540 30134 raft_consensus.cc:359] T 00000000000000000000000000000000 P 4bbfcb1513d4431383eb373d7557ebac [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4bbfcb1513d4431383eb373d7557ebac" member_type: VOTER }
I20260812 06:20:16.730695 30134 raft_consensus.cc:385] T 00000000000000000000000000000000 P 4bbfcb1513d4431383eb373d7557ebac [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:16.730767 30134 raft_consensus.cc:740] T 00000000000000000000000000000000 P 4bbfcb1513d4431383eb373d7557ebac [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 4bbfcb1513d4431383eb373d7557ebac, State: Initialized, Role: FOLLOWER
I20260812 06:20:16.731341 30134 consensus_queue.cc:260] T 00000000000000000000000000000000 P 4bbfcb1513d4431383eb373d7557ebac [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: "4bbfcb1513d4431383eb373d7557ebac" member_type: VOTER }
I20260812 06:20:16.731487 30134 raft_consensus.cc:399] T 00000000000000000000000000000000 P 4bbfcb1513d4431383eb373d7557ebac [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:16.731549 30134 raft_consensus.cc:493] T 00000000000000000000000000000000 P 4bbfcb1513d4431383eb373d7557ebac [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:16.731664 30134 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 4bbfcb1513d4431383eb373d7557ebac [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:16.732353 30134 raft_consensus.cc:515] T 00000000000000000000000000000000 P 4bbfcb1513d4431383eb373d7557ebac [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4bbfcb1513d4431383eb373d7557ebac" member_type: VOTER }
I20260812 06:20:16.732733 30134 leader_election.cc:304] T 00000000000000000000000000000000 P 4bbfcb1513d4431383eb373d7557ebac [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: 4bbfcb1513d4431383eb373d7557ebac; no voters: 
I20260812 06:20:16.732993 30134 leader_election.cc:290] T 00000000000000000000000000000000 P 4bbfcb1513d4431383eb373d7557ebac [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:16.733109 30137 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 4bbfcb1513d4431383eb373d7557ebac [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:16.733311 30137 raft_consensus.cc:697] T 00000000000000000000000000000000 P 4bbfcb1513d4431383eb373d7557ebac [term 1 LEADER]: Becoming Leader. State: Replica: 4bbfcb1513d4431383eb373d7557ebac, State: Running, Role: LEADER
I20260812 06:20:16.733737 30137 consensus_queue.cc:237] T 00000000000000000000000000000000 P 4bbfcb1513d4431383eb373d7557ebac [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: "4bbfcb1513d4431383eb373d7557ebac" member_type: VOTER }
I20260812 06:20:16.733840 30134 sys_catalog.cc:565] T 00000000000000000000000000000000 P 4bbfcb1513d4431383eb373d7557ebac [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:16.735395 30145 sys_catalog.cc:455] T 00000000000000000000000000000000 P 4bbfcb1513d4431383eb373d7557ebac [sys.catalog]: SysCatalogTable state changed. Reason: New leader 4bbfcb1513d4431383eb373d7557ebac. Latest consensus state: current_term: 1 leader_uuid: "4bbfcb1513d4431383eb373d7557ebac" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4bbfcb1513d4431383eb373d7557ebac" member_type: VOTER } }
I20260812 06:20:16.735400 30141 sys_catalog.cc:455] T 00000000000000000000000000000000 P 4bbfcb1513d4431383eb373d7557ebac [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "4bbfcb1513d4431383eb373d7557ebac" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4bbfcb1513d4431383eb373d7557ebac" member_type: VOTER } }
I20260812 06:20:16.735518 30145 sys_catalog.cc:458] T 00000000000000000000000000000000 P 4bbfcb1513d4431383eb373d7557ebac [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:16.735543 30141 sys_catalog.cc:458] T 00000000000000000000000000000000 P 4bbfcb1513d4431383eb373d7557ebac [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:16.735864 30164 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:16.735911 30017 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:16.737972 30164 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:16.741801 30164 catalog_manager.cc:1383] Generated new cluster ID: 17c30dae6c95465387547993b21ff245
I20260812 06:20:16.741858 30164 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:16.752384 30164 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:16.753098 30164 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:16.759896 30164 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 4bbfcb1513d4431383eb373d7557ebac: Generated new TSK 0
I20260812 06:20:16.760385 30164 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:16.768333 30017 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:16.771026 30180 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:20:16.770946 30177 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:20:16.771093 30017 server_base.cc:1061] running on GCE node
W20260812 06:20:16.770992 30174 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:20:16.771414 30017 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:16.771457 30017 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:20:16.771471 30017 hybrid_clock.cc:648] HybridClock initialized: now 1786515616771472 us; error 0 us; skew 500 ppm
I20260812 06:20:16.772272 30017 webserver.cc:533] Webserver started at http://127.29.80.65:42891/ using document root <none> and password file <none>
I20260812 06:20:16.772424 30017 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:16.772473 30017 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:16.772544 30017 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:16.772877 30017 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616667027-30017-0/minicluster-data/ts-0-root/instance:
uuid: "3ef31559e6124808bc469c7e8ae4cd36"
format_stamp: "Formatted at 2026-08-12 06:20:16 on dist-test-slave-42z9"
I20260812 06:20:16.774277 30017 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:16.775189 30189 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:20:16.775426 30017 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:16.775491 30017 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616667027-30017-0/minicluster-data/ts-0-root
uuid: "3ef31559e6124808bc469c7e8ae4cd36"
format_stamp: "Formatted at 2026-08-12 06:20:16 on dist-test-slave-42z9"
I20260812 06:20:16.775565 30017 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616667027-30017-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616667027-30017-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616667027-30017-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:20:16.783510 30017 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:16.784020 30017 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:16.784387 30017 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:16.785125 30017 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:16.785211 30017 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:16.785275 30017 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:16.785305 30017 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:16.791055 30017 rpc_server.cc:307] RPC server started. Bound to: 127.29.80.65:33297
I20260812 06:20:16.791107 30300 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.29.80.65:33297 every 8 connection(s)
I20260812 06:20:16.803820 30302 heartbeater.cc:344] Connected to a master server at 127.29.80.126:45561
I20260812 06:20:16.804029 30302 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:16.804510 30302 heartbeater.cc:507] Master 127.29.80.126:45561 requested a full tablet report, sending...
I20260812 06:20:16.805837 30078 ts_manager.cc:194] Registered new tserver with Master: 3ef31559e6124808bc469c7e8ae4cd36 (127.29.80.65:33297)
I20260812 06:20:16.805902 30017 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.014300361s
I20260812 06:20:16.807245 30078 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:54574
I20260812 06:20:16.814024 30078 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:54580:
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:20:16.826649 30239 tablet_service.cc:1511] Processing CreateTablet for tablet 0b33f97f9d0e40e980d2becd989c3c66 (DEFAULT_TABLE table=heavy-update-compaction-test [id=be91f0b511dd4fc6b84ac3b63a9bff17]), partition=
I20260812 06:20:16.827169 30239 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 0b33f97f9d0e40e980d2becd989c3c66. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:16.829322 30317 tablet_bootstrap.cc:492] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36: Bootstrap starting.
I20260812 06:20:16.830436 30317 tablet_bootstrap.cc:654] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:16.831453 30317 tablet_bootstrap.cc:492] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36: No bootstrap required, opened a new log
I20260812 06:20:16.831554 30317 ts_tablet_manager.cc:1403] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:16.831961 30317 raft_consensus.cc:359] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3ef31559e6124808bc469c7e8ae4cd36" member_type: VOTER last_known_addr { host: "127.29.80.65" port: 33297 } }
I20260812 06:20:16.832058 30317 raft_consensus.cc:385] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:16.832089 30317 raft_consensus.cc:740] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 3ef31559e6124808bc469c7e8ae4cd36, State: Initialized, Role: FOLLOWER
I20260812 06:20:16.832216 30317 consensus_queue.cc:260] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36 [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: "3ef31559e6124808bc469c7e8ae4cd36" member_type: VOTER last_known_addr { host: "127.29.80.65" port: 33297 } }
I20260812 06:20:16.832305 30317 raft_consensus.cc:399] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:16.832348 30317 raft_consensus.cc:493] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:16.832396 30317 raft_consensus.cc:3060] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:16.833024 30317 raft_consensus.cc:515] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3ef31559e6124808bc469c7e8ae4cd36" member_type: VOTER last_known_addr { host: "127.29.80.65" port: 33297 } }
I20260812 06:20:16.833155 30317 leader_election.cc:304] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36 [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: 3ef31559e6124808bc469c7e8ae4cd36; no voters: 
I20260812 06:20:16.833330 30317 leader_election.cc:290] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:16.833434 30320 raft_consensus.cc:2804] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:16.833632 30320 raft_consensus.cc:697] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36 [term 1 LEADER]: Becoming Leader. State: Replica: 3ef31559e6124808bc469c7e8ae4cd36, State: Running, Role: LEADER
I20260812 06:20:16.833715 30317 ts_tablet_manager.cc:1434] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:16.833823 30320 consensus_queue.cc:237] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36 [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: "3ef31559e6124808bc469c7e8ae4cd36" member_type: VOTER last_known_addr { host: "127.29.80.65" port: 33297 } }
I20260812 06:20:16.834129 30302 heartbeater.cc:499] Master 127.29.80.126:45561 was elected leader, sending a full tablet report...
I20260812 06:20:16.836635 30078 catalog_manager.cc:5719] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36 reported cstate change: term changed from 0 to 1, leader changed from <none> to 3ef31559e6124808bc469c7e8ae4cd36 (127.29.80.65). New cstate: current_term: 1 leader_uuid: "3ef31559e6124808bc469c7e8ae4cd36" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3ef31559e6124808bc469c7e8ae4cd36" member_type: VOTER last_known_addr { host: "127.29.80.65" port: 33297 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:16.899381 30017 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.053s	user 0.015s	sys 0.009s
I20260812 06:20:17.042008 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling FlushMRSOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=19.054940
I20260812 06:20:17.193496 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: FlushMRSOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.151s	user 0.120s	sys 0.020s Metrics: {"bytes_written":12307490,"cfile_init":1,"compiler_manager_pool.queue_time_us":197,"delete_count":0,"dirs.queue_time_us":44,"dirs.run_cpu_time_us":236,"dirs.run_wall_time_us":791,"drs_written":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4,"lbm_write_time_us":35452,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":106,"threads_started":1,"update_count":1500}
I20260812 06:20:17.194541 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling LogGCOp(0b33f97f9d0e40e980d2becd989c3c66): free 20743880 bytes of WAL
I20260812 06:20:17.194835 30195 log_reader.cc:385] T 0b33f97f9d0e40e980d2becd989c3c66: removed 2 log segments from log reader
I20260812 06:20:17.194913 30195 log.cc:1079] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/0b33f97f9d0e40e980d2becd989c3c66/wal-000000001 (ops 1-6)
I20260812 06:20:17.195030 30195 log.cc:1079] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/0b33f97f9d0e40e980d2becd989c3c66/wal-000000002 (ops 7-11)
I20260812 06:20:17.200356 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: LogGCOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.006s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:20:17.200717 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=2.188937
I20260812 06:20:17.218564 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.018s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6259,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.218986 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling MajorDeltaCompactionOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=1.000000
I20260812 06:20:17.358989 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: MajorDeltaCompactionOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.140s	user 0.087s	sys 0.049s 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":539,"lbm_read_time_us":8716,"lbm_reads_lt_1ms":464,"lbm_write_time_us":20223,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":276,"threads_started":5,"update_count":2000}
I20260812 06:20:17.359496 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling UndoDeltaBlockGCOp(0b33f97f9d0e40e980d2becd989c3c66): 16411392 bytes on disk
I20260812 06:20:17.360011 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: UndoDeltaBlockGCOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:20:17.360524 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=10.126437
I20260812 06:20:17.401265 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.041s	user 0.022s	sys 0.015s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15599,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:20:17.401736 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=2.188937
I20260812 06:20:17.425225 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.023s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4491,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.425689 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=2.188937
I20260812 06:20:17.434725 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.009s	user 0.007s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3396,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.435084 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling MajorDeltaCompactionOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=1.000000
I20260812 06:20:17.564950 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: MajorDeltaCompactionOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.130s	user 0.070s	sys 0.059s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774808,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":887,"lbm_read_time_us":8233,"lbm_reads_lt_1ms":573,"lbm_write_time_us":26661,"lbm_writes_lt_1ms":543,"mutex_wait_us":609,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":123904,"update_count":2500}
I20260812 06:20:17.565651 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=10.126437
I20260812 06:20:17.598577 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.033s	user 0.026s	sys 0.005s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13781,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:17.599038 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=2.188937
I20260812 06:20:17.613013 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5113,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.613482 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling MajorDeltaCompactionOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=1.000000
I20260812 06:20:17.730053 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: MajorDeltaCompactionOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.116s	user 0.096s	sys 0.021s 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":139,"lbm_read_time_us":7769,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22229,"lbm_writes_lt_1ms":443,"mutex_wait_us":36,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:17.730594 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=10.126437
I20260812 06:20:17.779066 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.048s	user 0.027s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18123,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:20:17.779649 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=2.188937
I20260812 06:20:17.789263 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3633,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.789723 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling MajorDeltaCompactionOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=1.000000
I20260812 06:20:17.919245 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: MajorDeltaCompactionOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.129s	user 0.097s	sys 0.032s 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":695,"lbm_read_time_us":9907,"lbm_reads_lt_1ms":472,"lbm_write_time_us":19962,"lbm_writes_lt_1ms":443,"mutex_wait_us":266,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:20:17.919751 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=10.126437
I20260812 06:20:17.958496 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.039s	user 0.023s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13427,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:17.959033 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=2.188937
I20260812 06:20:17.968966 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3683,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.969559 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling MajorDeltaCompactionOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=1.000000
I20260812 06:20:18.088639 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: MajorDeltaCompactionOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.119s	user 0.106s	sys 0.013s 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":112,"lbm_read_time_us":9454,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20661,"lbm_writes_lt_1ms":443,"mutex_wait_us":24,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15232,"update_count":2000}
I20260812 06:20:18.089126 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=10.126437
I20260812 06:20:18.127562 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.038s	user 0.027s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15811,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:18.128024 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=2.188937
I20260812 06:20:18.137619 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.009s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3702,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:18.138145 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling MajorDeltaCompactionOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=1.000000
I20260812 06:20:18.247280 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: MajorDeltaCompactionOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.109s	user 0.087s	sys 0.022s 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":215,"lbm_read_time_us":7163,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20198,"lbm_writes_lt_1ms":443,"mutex_wait_us":21,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":23040,"update_count":2000}
I20260812 06:20:18.247727 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=10.126437
I20260812 06:20:18.288623 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.041s	user 0.022s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12875,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:18.289108 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=2.188937
I20260812 06:20:18.298739 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3798,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:18.299124 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling FlushMRSOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=1.000000
I20260812 06:20:18.336913 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: FlushMRSOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.038s	user 0.021s	sys 0.004s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":33,"dirs.run_cpu_time_us":238,"dirs.run_wall_time_us":1451,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1340,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29,"spinlock_wait_cycles":5376}
I20260812 06:20:18.337818 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling LogGCOp(0b33f97f9d0e40e980d2becd989c3c66): free 116849513 bytes of WAL
I20260812 06:20:18.338045 30195 log_reader.cc:385] T 0b33f97f9d0e40e980d2becd989c3c66: removed 12 log segments from log reader
I20260812 06:20:18.338099 30195 log.cc:1079] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/0b33f97f9d0e40e980d2becd989c3c66/wal-000000003 (ops 12-16)
I20260812 06:20:18.338128 30195 log.cc:1079] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/0b33f97f9d0e40e980d2becd989c3c66/wal-000000004 (ops 17-21)
I20260812 06:20:18.338146 30195 log.cc:1079] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/0b33f97f9d0e40e980d2becd989c3c66/wal-000000005 (ops 22-26)
I20260812 06:20:18.338177 30195 log.cc:1079] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/0b33f97f9d0e40e980d2becd989c3c66/wal-000000006 (ops 27-30)
I20260812 06:20:18.338209 30195 log.cc:1079] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/0b33f97f9d0e40e980d2becd989c3c66/wal-000000007 (ops 31-35)
I20260812 06:20:18.338240 30195 log.cc:1079] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/0b33f97f9d0e40e980d2becd989c3c66/wal-000000008 (ops 36-40)
I20260812 06:20:18.338272 30195 log.cc:1079] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/0b33f97f9d0e40e980d2becd989c3c66/wal-000000009 (ops 41-44)
I20260812 06:20:18.338303 30195 log.cc:1079] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/0b33f97f9d0e40e980d2becd989c3c66/wal-000000010 (ops 45-49)
I20260812 06:20:18.338333 30195 log.cc:1079] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/0b33f97f9d0e40e980d2becd989c3c66/wal-000000011 (ops 50-54)
I20260812 06:20:18.338363 30195 log.cc:1079] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/0b33f97f9d0e40e980d2becd989c3c66/wal-000000012 (ops 55-58)
I20260812 06:20:18.338393 30195 log.cc:1079] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/0b33f97f9d0e40e980d2becd989c3c66/wal-000000013 (ops 59-63)
I20260812 06:20:18.338425 30195 log.cc:1079] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/0b33f97f9d0e40e980d2becd989c3c66/wal-000000014 (ops 64-68)
I20260812 06:20:18.358413 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: LogGCOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.020s	user 0.000s	sys 0.019s Metrics: {}
I20260812 06:20:18.358760 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=3.181125
I20260812 06:20:18.379380 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.020s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4573,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:18.379805 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling UndoDeltaBlockGCOp(0b33f97f9d0e40e980d2becd989c3c66): 462 bytes on disk
I20260812 06:20:18.380214 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: UndoDeltaBlockGCOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4}
I20260812 06:20:18.380673 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=2.188937
I20260812 06:20:18.389187 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.008s	user 0.003s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3185,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:18.389688 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling MajorDeltaCompactionOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=1.000000
I20260812 06:20:18.579551 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: MajorDeltaCompactionOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.190s	user 0.109s	sys 0.081s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877326,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":424,"lbm_read_time_us":12836,"lbm_reads_lt_1ms":674,"lbm_write_time_us":32164,"lbm_writes_lt_1ms":643,"mutex_wait_us":30,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":51328,"thread_start_us":72,"threads_started":1,"update_count":3000}
I20260812 06:20:18.580091 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=14.095187
I20260812 06:20:18.621788 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.042s	user 0.024s	sys 0.016s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":17749,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:18.622273 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling MajorDeltaCompactionOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=1.000000
I20260812 06:20:18.764293 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: MajorDeltaCompactionOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.142s	user 0.097s	sys 0.032s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672154,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":149,"lbm_read_time_us":9535,"lbm_reads_lt_1ms":463,"lbm_write_time_us":20878,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:18.764807 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=14.095187
I20260812 06:20:18.807250 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.042s	user 0.025s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":16557,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:18.807690 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=2.188937
I20260812 06:20:18.822600 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5718,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:18.823181 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling MajorDeltaCompactionOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=1.000000
I20260812 06:20:18.993572 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: MajorDeltaCompactionOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.170s	user 0.122s	sys 0.037s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":829,"lbm_read_time_us":10547,"lbm_reads_lt_1ms":572,"lbm_write_time_us":24732,"lbm_writes_lt_1ms":543,"mutex_wait_us":34,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":63232,"update_count":2500}
I20260812 06:20:18.994068 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=14.095187
I20260812 06:20:19.038791 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.045s	user 0.026s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18861,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:19.039259 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=2.188937
I20260812 06:20:19.049101 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3640,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:19.049635 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling MajorDeltaCompactionOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=1.000000
I20260812 06:20:19.187958 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: MajorDeltaCompactionOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.138s	user 0.097s	sys 0.041s 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":276,"lbm_read_time_us":8958,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27400,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:20:19.188484 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=10.126437
I20260812 06:20:19.217192 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.029s	user 0.014s	sys 0.011s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":12305,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:19.217631 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=2.188937
I20260812 06:20:19.229801 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.012s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4492,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:19.231992 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling MajorDeltaCompactionOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=1.000000
I20260812 06:20:19.348755 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: MajorDeltaCompactionOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.117s	user 0.097s	sys 0.019s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":104,"lbm_read_time_us":6783,"lbm_reads_lt_1ms":464,"lbm_write_time_us":22803,"lbm_writes_lt_1ms":443,"mutex_wait_us":59,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:19.349208 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=10.126437
I20260812 06:20:19.385591 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.036s	user 0.024s	sys 0.007s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":12345,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:19.386144 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=2.188937
I20260812 06:20:19.395787 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3637,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:19.396181 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling MajorDeltaCompactionOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=1.000000
I20260812 06:20:19.516129 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: MajorDeltaCompactionOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.120s	user 0.092s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672280,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":184,"lbm_read_time_us":7221,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22489,"lbm_writes_lt_1ms":443,"mutex_wait_us":50,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5248,"update_count":2000}
I20260812 06:20:19.516618 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=10.126437
I20260812 06:20:19.564903 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.048s	user 0.022s	sys 0.019s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14704,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:20:19.565474 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=2.188937
I20260812 06:20:19.574855 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.009s	user 0.003s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3576,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:19.575306 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling FlushMRSOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=1.000000
I20260812 06:20:19.614467 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: FlushMRSOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.039s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":50,"dirs.run_cpu_time_us":192,"dirs.run_wall_time_us":1206,"drs_written":1,"lbm_read_time_us":34,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1533,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:19.615134 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling LogGCOp(0b33f97f9d0e40e980d2becd989c3c66): free 115943177 bytes of WAL
I20260812 06:20:19.615352 30195 log_reader.cc:385] T 0b33f97f9d0e40e980d2becd989c3c66: removed 11 log segments from log reader
I20260812 06:20:19.615408 30195 log.cc:1079] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/0b33f97f9d0e40e980d2becd989c3c66/wal-000000015 (ops 69-73)
I20260812 06:20:19.615451 30195 log.cc:1079] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/0b33f97f9d0e40e980d2becd989c3c66/wal-000000016 (ops 74-78)
I20260812 06:20:19.615484 30195 log.cc:1079] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/0b33f97f9d0e40e980d2becd989c3c66/wal-000000017 (ops 79-83)
I20260812 06:20:19.615506 30195 log.cc:1079] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/0b33f97f9d0e40e980d2becd989c3c66/wal-000000018 (ops 84-88)
I20260812 06:20:19.615533 30195 log.cc:1079] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/0b33f97f9d0e40e980d2becd989c3c66/wal-000000019 (ops 89-93)
I20260812 06:20:19.615564 30195 log.cc:1079] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/0b33f97f9d0e40e980d2becd989c3c66/wal-000000020 (ops 94-98)
I20260812 06:20:19.615597 30195 log.cc:1079] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/0b33f97f9d0e40e980d2becd989c3c66/wal-000000021 (ops 99-103)
I20260812 06:20:19.615625 30195 log.cc:1079] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/0b33f97f9d0e40e980d2becd989c3c66/wal-000000022 (ops 104-108)
I20260812 06:20:19.615651 30195 log.cc:1079] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/0b33f97f9d0e40e980d2becd989c3c66/wal-000000023 (ops 109-113)
I20260812 06:20:19.615677 30195 log.cc:1079] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/0b33f97f9d0e40e980d2becd989c3c66/wal-000000024 (ops 114-118)
I20260812 06:20:19.615702 30195 log.cc:1079] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/0b33f97f9d0e40e980d2becd989c3c66/wal-000000025 (ops 119-123)
I20260812 06:20:19.639622 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: LogGCOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.024s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:20:19.640067 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling UndoDeltaBlockGCOp(0b33f97f9d0e40e980d2becd989c3c66): 446 bytes on disk
I20260812 06:20:19.640571 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: UndoDeltaBlockGCOp(0b33f97f9d0e40e980d2becd989c3c66) 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:20:19.641168 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=3.181125
I20260812 06:20:19.656255 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.015s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4103,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:19.656610 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=2.188937
I20260812 06:20:19.665272 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.009s	user 0.003s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3238,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:19.665647 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling MajorDeltaCompactionOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=1.000000
I20260812 06:20:19.841694 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: MajorDeltaCompactionOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.176s	user 0.114s	sys 0.060s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877327,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":852,"lbm_read_time_us":11330,"lbm_reads_lt_1ms":674,"lbm_write_time_us":27618,"lbm_writes_lt_1ms":643,"mutex_wait_us":1402,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3200,"thread_start_us":107,"threads_started":1,"update_count":3000}
I20260812 06:20:19.842242 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=14.095187
I20260812 06:20:19.892619 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.050s	user 0.033s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25554,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:20:19.893137 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=2.188937
I20260812 06:20:19.903602 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3649,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:19.904163 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling MajorDeltaCompactionOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=1.000000
I20260812 06:20:20.056291 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: MajorDeltaCompactionOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.152s	user 0.109s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":539,"lbm_read_time_us":10099,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25381,"lbm_writes_lt_1ms":543,"mutex_wait_us":243,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2500}
I20260812 06:20:20.056840 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=14.095187
I20260812 06:20:20.116465 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.059s	user 0.033s	sys 0.023s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23789,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:20.117004 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=2.188937
I20260812 06:20:20.130872 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5529,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.131371 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling MajorDeltaCompactionOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=1.000000
I20260812 06:20:20.288091 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: MajorDeltaCompactionOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.157s	user 0.100s	sys 0.055s 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":295,"lbm_read_time_us":10967,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27882,"lbm_writes_lt_1ms":543,"mutex_wait_us":67,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:20:20.288661 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=11.118625
I20260812 06:20:20.339458 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.051s	user 0.021s	sys 0.023s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15416,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:20.340337 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=3.181125
I20260812 06:20:20.351298 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.011s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4307782,"delete_count":0,"lbm_write_time_us":3886,"lbm_writes_lt_1ms":108,"reinsert_count":0,"update_count":525}
I20260812 06:20:20.351801 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=2.188937
I20260812 06:20:20.360903 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.009s	user 0.002s	sys 0.005s Metrics: {"bytes_written":3487280,"delete_count":0,"lbm_write_time_us":3381,"lbm_writes_lt_1ms":88,"reinsert_count":0,"update_count":425}
I20260812 06:20:20.361263 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling MajorDeltaCompactionOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=1.000000
I20260812 06:20:20.527482 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: MajorDeltaCompactionOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.166s	user 0.118s	sys 0.044s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774797,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":717,"lbm_read_time_us":10860,"lbm_reads_lt_1ms":573,"lbm_write_time_us":27649,"lbm_writes_lt_1ms":543,"mutex_wait_us":224,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:20:20.527945 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=11.118625
I20260812 06:20:20.562599 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.034s	user 0.026s	sys 0.007s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14163,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:20.563120 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=2.188937
I20260812 06:20:20.592402 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.029s	user 0.006s	sys 0.011s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4643,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:20.592877 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=2.188937
I20260812 06:20:20.602816 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3880,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.603269 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling MajorDeltaCompactionOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=1.000000
I20260812 06:20:20.770268 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: MajorDeltaCompactionOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.167s	user 0.097s	sys 0.059s 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":191,"lbm_read_time_us":10943,"lbm_reads_lt_1ms":573,"lbm_write_time_us":25425,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:20.771166 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=14.095187
I20260812 06:20:20.821584 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.050s	user 0.027s	sys 0.023s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21071,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:20.822114 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=2.188937
I20260812 06:20:20.843334 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.021s	user 0.008s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5764,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.843767 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling MajorDeltaCompactionOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=1.000000
I20260812 06:20:21.000945 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: MajorDeltaCompactionOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.157s	user 0.106s	sys 0.049s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1371,"lbm_read_time_us":9448,"lbm_reads_lt_1ms":564,"lbm_write_time_us":26593,"lbm_writes_lt_1ms":543,"mutex_wait_us":315,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:20:21.001538 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=14.095187
I20260812 06:20:21.052055 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.050s	user 0.038s	sys 0.009s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21426,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:21.052549 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=2.188937
I20260812 06:20:21.062660 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.010s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3643,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.063128 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling FlushMRSOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=1.000000
I20260812 06:20:21.098980 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: FlushMRSOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.036s	user 0.026s	sys 0.008s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":50,"dirs.run_cpu_time_us":205,"dirs.run_wall_time_us":1195,"drs_written":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1679,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:20:21.099757 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling LogGCOp(0b33f97f9d0e40e980d2becd989c3c66): free 129320767 bytes of WAL
I20260812 06:20:21.099975 30195 log_reader.cc:385] T 0b33f97f9d0e40e980d2becd989c3c66: removed 13 log segments from log reader
I20260812 06:20:21.100019 30195 log.cc:1079] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/0b33f97f9d0e40e980d2becd989c3c66/wal-000000026 (ops 124-128)
I20260812 06:20:21.100049 30195 log.cc:1079] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/0b33f97f9d0e40e980d2becd989c3c66/wal-000000027 (ops 129-132)
I20260812 06:20:21.100091 30195 log.cc:1079] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/0b33f97f9d0e40e980d2becd989c3c66/wal-000000028 (ops 133-137)
I20260812 06:20:21.100124 30195 log.cc:1079] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/0b33f97f9d0e40e980d2becd989c3c66/wal-000000029 (ops 138-142)
I20260812 06:20:21.100155 30195 log.cc:1079] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/0b33f97f9d0e40e980d2becd989c3c66/wal-000000030 (ops 143-146)
I20260812 06:20:21.100185 30195 log.cc:1079] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/0b33f97f9d0e40e980d2becd989c3c66/wal-000000031 (ops 147-151)
I20260812 06:20:21.100216 30195 log.cc:1079] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/0b33f97f9d0e40e980d2becd989c3c66/wal-000000032 (ops 152-156)
I20260812 06:20:21.100246 30195 log.cc:1079] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/0b33f97f9d0e40e980d2becd989c3c66/wal-000000033 (ops 157-161)
I20260812 06:20:21.100277 30195 log.cc:1079] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/0b33f97f9d0e40e980d2becd989c3c66/wal-000000034 (ops 162-166)
I20260812 06:20:21.100308 30195 log.cc:1079] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/0b33f97f9d0e40e980d2becd989c3c66/wal-000000035 (ops 167-171)
I20260812 06:20:21.100339 30195 log.cc:1079] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/0b33f97f9d0e40e980d2becd989c3c66/wal-000000036 (ops 172-176)
I20260812 06:20:21.100370 30195 log.cc:1079] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/0b33f97f9d0e40e980d2becd989c3c66/wal-000000037 (ops 177-181)
I20260812 06:20:21.100402 30195 log.cc:1079] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/0b33f97f9d0e40e980d2becd989c3c66/wal-000000038 (ops 182-186)
I20260812 06:20:21.121604 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: LogGCOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.022s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:20:21.122009 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling UndoDeltaBlockGCOp(0b33f97f9d0e40e980d2becd989c3c66): 491 bytes on disk
I20260812 06:20:21.122457 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: UndoDeltaBlockGCOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:20:21.122977 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=2.188937
I20260812 06:20:21.136317 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.013s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5259,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.136720 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling MajorDeltaCompactionOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=1.000000
I20260812 06:20:21.334347 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: MajorDeltaCompactionOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.197s	user 0.132s	sys 0.064s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877219,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1742,"lbm_read_time_us":14449,"lbm_reads_lt_1ms":669,"lbm_write_time_us":32232,"lbm_writes_lt_1ms":643,"mutex_wait_us":1076,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1280,"thread_start_us":81,"threads_started":1,"update_count":3000}
I20260812 06:20:21.335029 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=14.095187
I20260812 06:20:21.380611 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.045s	user 0.031s	sys 0.011s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":16146,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:21.381276 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=2.188937
I20260812 06:20:21.394543 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: FlushDeltaMemStoresOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.013s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5934,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":102,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.394987 30303 maintenance_manager.cc:419] P 3ef31559e6124808bc469c7e8ae4cd36: Scheduling MajorDeltaCompactionOp(0b33f97f9d0e40e980d2becd989c3c66): perf score=1.000000
I20260812 06:20:21.416631 30017 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.517s	user 1.622s	sys 0.168s
I20260812 06:20:21.487840 30017 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.071s	user 0.001s	sys 0.000s
I20260812 06:20:21.488401 30017 tablet_server.cc:179] TabletServer@127.29.80.65:0 shutting down...
I20260812 06:20:21.534953 30195 maintenance_manager.cc:643] P 3ef31559e6124808bc469c7e8ae4cd36: MajorDeltaCompactionOp(0b33f97f9d0e40e980d2becd989c3c66) complete. Timing: real 0.140s	user 0.104s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":190,"lbm_read_time_us":11414,"lbm_reads_lt_1ms":564,"lbm_write_time_us":21940,"lbm_writes_lt_1ms":543,"mutex_wait_us":54,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5632,"update_count":2500}
I20260812 06:20:21.535599 30017 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:21.535977 30017 tablet_replica.cc:333] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36: stopping tablet replica
I20260812 06:20:21.536185 30017 raft_consensus.cc:2243] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:21.536422 30017 raft_consensus.cc:2272] T 0b33f97f9d0e40e980d2becd989c3c66 P 3ef31559e6124808bc469c7e8ae4cd36 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:21.551705 30017 tablet_server.cc:196] TabletServer@127.29.80.65:0 shutdown complete.
I20260812 06:20:21.579807 30017 master.cc:562] Master@127.29.80.126:45561 shutting down...
I20260812 06:20:21.582998 30017 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 4bbfcb1513d4431383eb373d7557ebac [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:21.583148 30017 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 4bbfcb1513d4431383eb373d7557ebac [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:21.583218 30017 tablet_replica.cc:333] T 00000000000000000000000000000000 P 4bbfcb1513d4431383eb373d7557ebac: stopping tablet replica
I20260812 06:20:21.595084 30017 master.cc:584] Master@127.29.80.126:45561 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (4986 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:20:21.674947 30017 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.29.80.126:39021
I20260812 06:20:21.675331 30017 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:21.677186 30354 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:20:21.677276 30017 server_base.cc:1061] running on GCE node
W20260812 06:20:21.677271 30353 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:20:21.677285 30361 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:20:21.677654 30017 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:21.677698 30017 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:20:21.677712 30017 hybrid_clock.cc:648] HybridClock initialized: now 1786515621677712 us; error 0 us; skew 500 ppm
I20260812 06:20:21.678411 30017 webserver.cc:533] Webserver started at http://127.29.80.126:44471/ using document root <none> and password file <none>
I20260812 06:20:21.678531 30017 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:21.678571 30017 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:21.678625 30017 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:21.678936 30017 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616667027-30017-0/minicluster-data/master-0-root/instance:
uuid: "e2577883c2234dd09870a33e82ede8f3"
format_stamp: "Formatted at 2026-08-12 06:20:21 on dist-test-slave-42z9"
I20260812 06:20:21.680317 30017 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:21.681111 30372 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:20:21.681319 30017 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:21.681388 30017 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616667027-30017-0/minicluster-data/master-0-root
uuid: "e2577883c2234dd09870a33e82ede8f3"
format_stamp: "Formatted at 2026-08-12 06:20:21 on dist-test-slave-42z9"
I20260812 06:20:21.681479 30017 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616667027-30017-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616667027-30017-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616667027-30017-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:20:21.691304 30017 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:21.691594 30017 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:21.695349 30017 rpc_server.cc:307] RPC server started. Bound to: 127.29.80.126:39021
I20260812 06:20:21.695812 30459 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.29.80.126:39021 every 8 connection(s)
I20260812 06:20:21.696344 30460 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:20:21.697980 30460 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P e2577883c2234dd09870a33e82ede8f3: Bootstrap starting.
I20260812 06:20:21.698674 30460 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P e2577883c2234dd09870a33e82ede8f3: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:21.699527 30460 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P e2577883c2234dd09870a33e82ede8f3: No bootstrap required, opened a new log
I20260812 06:20:21.699879 30460 raft_consensus.cc:359] T 00000000000000000000000000000000 P e2577883c2234dd09870a33e82ede8f3 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e2577883c2234dd09870a33e82ede8f3" member_type: VOTER }
I20260812 06:20:21.699956 30460 raft_consensus.cc:385] T 00000000000000000000000000000000 P e2577883c2234dd09870a33e82ede8f3 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:21.699988 30460 raft_consensus.cc:740] T 00000000000000000000000000000000 P e2577883c2234dd09870a33e82ede8f3 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: e2577883c2234dd09870a33e82ede8f3, State: Initialized, Role: FOLLOWER
I20260812 06:20:21.700126 30460 consensus_queue.cc:260] T 00000000000000000000000000000000 P e2577883c2234dd09870a33e82ede8f3 [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: "e2577883c2234dd09870a33e82ede8f3" member_type: VOTER }
I20260812 06:20:21.700203 30460 raft_consensus.cc:399] T 00000000000000000000000000000000 P e2577883c2234dd09870a33e82ede8f3 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:21.700238 30460 raft_consensus.cc:493] T 00000000000000000000000000000000 P e2577883c2234dd09870a33e82ede8f3 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:21.700287 30460 raft_consensus.cc:3060] T 00000000000000000000000000000000 P e2577883c2234dd09870a33e82ede8f3 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:21.700893 30460 raft_consensus.cc:515] T 00000000000000000000000000000000 P e2577883c2234dd09870a33e82ede8f3 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e2577883c2234dd09870a33e82ede8f3" member_type: VOTER }
I20260812 06:20:21.701004 30460 leader_election.cc:304] T 00000000000000000000000000000000 P e2577883c2234dd09870a33e82ede8f3 [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: e2577883c2234dd09870a33e82ede8f3; no voters: 
I20260812 06:20:21.701161 30460 leader_election.cc:290] T 00000000000000000000000000000000 P e2577883c2234dd09870a33e82ede8f3 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:21.701254 30463 raft_consensus.cc:2804] T 00000000000000000000000000000000 P e2577883c2234dd09870a33e82ede8f3 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:21.701454 30463 raft_consensus.cc:697] T 00000000000000000000000000000000 P e2577883c2234dd09870a33e82ede8f3 [term 1 LEADER]: Becoming Leader. State: Replica: e2577883c2234dd09870a33e82ede8f3, State: Running, Role: LEADER
I20260812 06:20:21.701581 30460 sys_catalog.cc:565] T 00000000000000000000000000000000 P e2577883c2234dd09870a33e82ede8f3 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:21.701607 30463 consensus_queue.cc:237] T 00000000000000000000000000000000 P e2577883c2234dd09870a33e82ede8f3 [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: "e2577883c2234dd09870a33e82ede8f3" member_type: VOTER }
I20260812 06:20:21.701997 30467 sys_catalog.cc:455] T 00000000000000000000000000000000 P e2577883c2234dd09870a33e82ede8f3 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "e2577883c2234dd09870a33e82ede8f3" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e2577883c2234dd09870a33e82ede8f3" member_type: VOTER } }
I20260812 06:20:21.702028 30469 sys_catalog.cc:455] T 00000000000000000000000000000000 P e2577883c2234dd09870a33e82ede8f3 [sys.catalog]: SysCatalogTable state changed. Reason: New leader e2577883c2234dd09870a33e82ede8f3. Latest consensus state: current_term: 1 leader_uuid: "e2577883c2234dd09870a33e82ede8f3" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e2577883c2234dd09870a33e82ede8f3" member_type: VOTER } }
I20260812 06:20:21.702167 30469 sys_catalog.cc:458] T 00000000000000000000000000000000 P e2577883c2234dd09870a33e82ede8f3 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:21.702391 30467 sys_catalog.cc:458] T 00000000000000000000000000000000 P e2577883c2234dd09870a33e82ede8f3 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:21.702601 30475 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:21.703460 30475 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:21.703680 30017 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:21.705125 30475 catalog_manager.cc:1383] Generated new cluster ID: 5e6b147471a542c59e36fb327522b7b4
I20260812 06:20:21.705179 30475 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:21.711608 30475 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:21.712085 30475 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:21.718344 30475 catalog_manager.cc:6092] T 00000000000000000000000000000000 P e2577883c2234dd09870a33e82ede8f3: Generated new TSK 0
I20260812 06:20:21.718482 30475 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:21.719570 30017 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:21.721184 30494 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:21.721186 30492 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:20:21.721246 30497 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:20:21.721334 30017 server_base.cc:1061] running on GCE node
I20260812 06:20:21.721518 30017 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:21.721566 30017 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:20:21.721580 30017 hybrid_clock.cc:648] HybridClock initialized: now 1786515621721580 us; error 0 us; skew 500 ppm
I20260812 06:20:21.722311 30017 webserver.cc:533] Webserver started at http://127.29.80.65:46471/ using document root <none> and password file <none>
I20260812 06:20:21.722443 30017 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:21.722487 30017 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:21.722566 30017 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:21.722883 30017 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616667027-30017-0/minicluster-data/ts-0-root/instance:
uuid: "c74a70cc44994e0fba80213b6b87baa7"
format_stamp: "Formatted at 2026-08-12 06:20:21 on dist-test-slave-42z9"
I20260812 06:20:21.724192 30017 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:20:21.724989 30504 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:20:21.725184 30017 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:21.725241 30017 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616667027-30017-0/minicluster-data/ts-0-root
uuid: "c74a70cc44994e0fba80213b6b87baa7"
format_stamp: "Formatted at 2026-08-12 06:20:21 on dist-test-slave-42z9"
I20260812 06:20:21.725302 30017 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616667027-30017-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616667027-30017-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616667027-30017-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:20:21.733736 30017 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:21.734021 30017 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:21.734269 30017 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:21.734687 30017 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:21.734723 30017 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:21.734763 30017 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:21.734790 30017 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:21.738739 30017 rpc_server.cc:307] RPC server started. Bound to: 127.29.80.65:39891
I20260812 06:20:21.739935 30616 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.29.80.65:39891 every 8 connection(s)
I20260812 06:20:21.743954 30617 heartbeater.cc:344] Connected to a master server at 127.29.80.126:39021
I20260812 06:20:21.744040 30617 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:21.744238 30617 heartbeater.cc:507] Master 127.29.80.126:39021 requested a full tablet report, sending...
I20260812 06:20:21.744787 30401 ts_manager.cc:194] Registered new tserver with Master: c74a70cc44994e0fba80213b6b87baa7 (127.29.80.65:39891)
I20260812 06:20:21.744865 30017 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.005466826s
I20260812 06:20:21.745539 30401 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:42668
I20260812 06:20:21.751015 30401 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:42684:
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:20:21.758520 30556 tablet_service.cc:1511] Processing CreateTablet for tablet f61b1fa8d7444907b15bf28d5e0b97b6 (DEFAULT_TABLE table=heavy-update-compaction-test [id=aa5604b040bf4d28b7277e90e69fe168]), partition=
I20260812 06:20:21.758746 30556 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet f61b1fa8d7444907b15bf28d5e0b97b6. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:21.760501 30636 tablet_bootstrap.cc:492] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7: Bootstrap starting.
I20260812 06:20:21.761401 30636 tablet_bootstrap.cc:654] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:21.762285 30636 tablet_bootstrap.cc:492] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7: No bootstrap required, opened a new log
I20260812 06:20:21.762353 30636 ts_tablet_manager.cc:1403] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:20:21.762642 30636 raft_consensus.cc:359] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c74a70cc44994e0fba80213b6b87baa7" member_type: VOTER last_known_addr { host: "127.29.80.65" port: 39891 } }
I20260812 06:20:21.762717 30636 raft_consensus.cc:385] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:21.762737 30636 raft_consensus.cc:740] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: c74a70cc44994e0fba80213b6b87baa7, State: Initialized, Role: FOLLOWER
I20260812 06:20:21.762828 30636 consensus_queue.cc:260] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7 [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: "c74a70cc44994e0fba80213b6b87baa7" member_type: VOTER last_known_addr { host: "127.29.80.65" port: 39891 } }
I20260812 06:20:21.762882 30636 raft_consensus.cc:399] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:21.762907 30636 raft_consensus.cc:493] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:21.762939 30636 raft_consensus.cc:3060] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:21.763545 30636 raft_consensus.cc:515] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c74a70cc44994e0fba80213b6b87baa7" member_type: VOTER last_known_addr { host: "127.29.80.65" port: 39891 } }
I20260812 06:20:21.763666 30636 leader_election.cc:304] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7 [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: c74a70cc44994e0fba80213b6b87baa7; no voters: 
I20260812 06:20:21.763851 30636 leader_election.cc:290] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:21.763967 30638 raft_consensus.cc:2804] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:21.764155 30617 heartbeater.cc:499] Master 127.29.80.126:39021 was elected leader, sending a full tablet report...
I20260812 06:20:21.764205 30638 raft_consensus.cc:697] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7 [term 1 LEADER]: Becoming Leader. State: Replica: c74a70cc44994e0fba80213b6b87baa7, State: Running, Role: LEADER
I20260812 06:20:21.764336 30638 consensus_queue.cc:237] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7 [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: "c74a70cc44994e0fba80213b6b87baa7" member_type: VOTER last_known_addr { host: "127.29.80.65" port: 39891 } }
I20260812 06:20:21.764424 30636 ts_tablet_manager.cc:1434] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:21.765540 30401 catalog_manager.cc:5719] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7 reported cstate change: term changed from 0 to 1, leader changed from <none> to c74a70cc44994e0fba80213b6b87baa7 (127.29.80.65). New cstate: current_term: 1 leader_uuid: "c74a70cc44994e0fba80213b6b87baa7" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c74a70cc44994e0fba80213b6b87baa7" member_type: VOTER last_known_addr { host: "127.29.80.65" port: 39891 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:21.817175 30017 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.048s	user 0.009s	sys 0.011s
I20260812 06:20:21.990386 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling FlushMRSOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=23.023690
I20260812 06:20:22.152815 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: FlushMRSOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.162s	user 0.095s	sys 0.063s Metrics: {"bytes_written":13292062,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":186,"dirs.run_cpu_time_us":220,"dirs.run_wall_time_us":900,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":41666,"lbm_writes_lt_1ms":881,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"spinlock_wait_cycles":2816,"update_count":1620}
I20260812 06:20:22.153381 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling LogGCOp(f61b1fa8d7444907b15bf28d5e0b97b6): free 20743880 bytes of WAL
I20260812 06:20:22.153654 30513 log_reader.cc:385] T f61b1fa8d7444907b15bf28d5e0b97b6: removed 2 log segments from log reader
I20260812 06:20:22.153719 30513 log.cc:1079] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/f61b1fa8d7444907b15bf28d5e0b97b6/wal-000000001 (ops 1-6)
I20260812 06:20:22.153761 30513 log.cc:1079] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/f61b1fa8d7444907b15bf28d5e0b97b6/wal-000000002 (ops 7-11)
I20260812 06:20:22.158464 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: LogGCOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.005s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:20:22.158867 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling UndoDeltaBlockGCOp(f61b1fa8d7444907b15bf28d5e0b97b6): 20513813 bytes on disk
I20260812 06:20:22.159271 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: UndoDeltaBlockGCOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4}
I20260812 06:20:22.159698 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=2.188937
I20260812 06:20:22.173892 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.014s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102663,"delete_count":0,"lbm_write_time_us":5802,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.174229 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=1.196750
I20260812 06:20:22.183184 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.009s	user 0.007s	sys 0.000s Metrics: {"bytes_written":3118055,"delete_count":0,"lbm_write_time_us":3075,"lbm_writes_lt_1ms":79,"reinsert_count":0,"update_count":380}
I20260812 06:20:22.183589 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling MajorDeltaCompactionOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=1.000000
I20260812 06:20:22.354925 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: MajorDeltaCompactionOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.171s	user 0.113s	sys 0.058s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815775,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":519,"lbm_read_time_us":12651,"lbm_reads_lt_1ms":569,"lbm_write_time_us":25956,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3584,"thread_start_us":291,"threads_started":5,"update_count":2500}
I20260812 06:20:22.355477 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=14.095187
I20260812 06:20:22.407501 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.052s	user 0.025s	sys 0.023s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":17942,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:22.407979 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=2.188937
I20260812 06:20:22.417745 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3803,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.418123 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling MajorDeltaCompactionOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=1.000000
I20260812 06:20:22.595139 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: MajorDeltaCompactionOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.177s	user 0.127s	sys 0.039s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":536,"lbm_read_time_us":11094,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26742,"lbm_writes_lt_1ms":543,"mutex_wait_us":245,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3584,"update_count":2500}
I20260812 06:20:22.595607 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=14.095187
I20260812 06:20:22.649153 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.053s	user 0.024s	sys 0.021s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":17949,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:22.649714 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=2.188937
I20260812 06:20:22.659417 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3756,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.659771 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling MajorDeltaCompactionOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=1.000000
I20260812 06:20:22.826025 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: MajorDeltaCompactionOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.166s	user 0.113s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":224,"lbm_read_time_us":11874,"lbm_reads_lt_1ms":572,"lbm_write_time_us":24545,"lbm_writes_lt_1ms":543,"mutex_wait_us":42,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14976,"update_count":2500}
I20260812 06:20:22.826542 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=11.118625
I20260812 06:20:22.859180 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.032s	user 0.015s	sys 0.016s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13901,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:22.859686 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=2.188937
I20260812 06:20:22.872216 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4379,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:22.872706 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling MajorDeltaCompactionOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=1.000000
I20260812 06:20:22.991514 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: MajorDeltaCompactionOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.119s	user 0.082s	sys 0.035s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713263,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":159,"lbm_read_time_us":6814,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23348,"lbm_writes_lt_1ms":443,"mutex_wait_us":41,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2000}
I20260812 06:20:22.992023 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=10.126437
I20260812 06:20:23.026714 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.035s	user 0.028s	sys 0.005s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14829,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:23.027139 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=2.188937
I20260812 06:20:23.037314 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3747,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.037824 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling MajorDeltaCompactionOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=1.000000
I20260812 06:20:23.163892 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: MajorDeltaCompactionOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.126s	user 0.114s	sys 0.011s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1191,"lbm_read_time_us":7998,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22477,"lbm_writes_lt_1ms":443,"mutex_wait_us":280,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":50304,"update_count":2000}
I20260812 06:20:23.164376 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=10.126437
I20260812 06:20:23.207360 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.043s	user 0.025s	sys 0.004s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":13713,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:23.207890 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=2.188937
I20260812 06:20:23.217242 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.009s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3520,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.217723 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling MajorDeltaCompactionOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=1.000000
I20260812 06:20:23.329308 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: MajorDeltaCompactionOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.111s	user 0.084s	sys 0.027s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":565,"lbm_read_time_us":8358,"lbm_reads_lt_1ms":472,"lbm_write_time_us":19566,"lbm_writes_lt_1ms":443,"mutex_wait_us":278,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7552,"update_count":2000}
I20260812 06:20:23.329905 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=10.126437
I20260812 06:20:23.376482 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.046s	user 0.023s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14445,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:23.376964 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=2.188937
I20260812 06:20:23.386725 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3799,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.387069 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling FlushMRSOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=1.000000
I20260812 06:20:23.415715 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: FlushMRSOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.029s	user 0.025s	sys 0.000s Metrics: {"bytes_written":1275444,"cfile_init":1,"dirs.queue_time_us":62,"dirs.run_cpu_time_us":257,"dirs.run_wall_time_us":1284,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1373,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:23.416356 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling MajorDeltaCompactionOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=1.000000
I20260812 06:20:23.565831 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: MajorDeltaCompactionOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.149s	user 0.110s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":281,"lbm_read_time_us":10454,"lbm_reads_lt_1ms":464,"lbm_write_time_us":21141,"lbm_writes_lt_1ms":443,"mutex_wait_us":41,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6272,"update_count":2000}
I20260812 06:20:23.566318 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling LogGCOp(f61b1fa8d7444907b15bf28d5e0b97b6): free 132571308 bytes of WAL
I20260812 06:20:23.566537 30513 log_reader.cc:385] T f61b1fa8d7444907b15bf28d5e0b97b6: removed 13 log segments from log reader
I20260812 06:20:23.566586 30513 log.cc:1079] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/f61b1fa8d7444907b15bf28d5e0b97b6/wal-000000003 (ops 12-16)
I20260812 06:20:23.566620 30513 log.cc:1079] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/f61b1fa8d7444907b15bf28d5e0b97b6/wal-000000004 (ops 17-21)
I20260812 06:20:23.566649 30513 log.cc:1079] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/f61b1fa8d7444907b15bf28d5e0b97b6/wal-000000005 (ops 22-26)
I20260812 06:20:23.566709 30513 log.cc:1079] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/f61b1fa8d7444907b15bf28d5e0b97b6/wal-000000006 (ops 27-31)
I20260812 06:20:23.566741 30513 log.cc:1079] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/f61b1fa8d7444907b15bf28d5e0b97b6/wal-000000007 (ops 32-36)
I20260812 06:20:23.566787 30513 log.cc:1079] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/f61b1fa8d7444907b15bf28d5e0b97b6/wal-000000008 (ops 37-41)
I20260812 06:20:23.566816 30513 log.cc:1079] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/f61b1fa8d7444907b15bf28d5e0b97b6/wal-000000009 (ops 42-46)
I20260812 06:20:23.566865 30513 log.cc:1079] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/f61b1fa8d7444907b15bf28d5e0b97b6/wal-000000010 (ops 47-51)
I20260812 06:20:23.566896 30513 log.cc:1079] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/f61b1fa8d7444907b15bf28d5e0b97b6/wal-000000011 (ops 52-56)
I20260812 06:20:23.566938 30513 log.cc:1079] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/f61b1fa8d7444907b15bf28d5e0b97b6/wal-000000012 (ops 57-60)
I20260812 06:20:23.566967 30513 log.cc:1079] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/f61b1fa8d7444907b15bf28d5e0b97b6/wal-000000013 (ops 61-65)
I20260812 06:20:23.567005 30513 log.cc:1079] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/f61b1fa8d7444907b15bf28d5e0b97b6/wal-000000014 (ops 66-70)
I20260812 06:20:23.567035 30513 log.cc:1079] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/f61b1fa8d7444907b15bf28d5e0b97b6/wal-000000015 (ops 71-74)
I20260812 06:20:23.589803 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: LogGCOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.023s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:20:23.590238 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling UndoDeltaBlockGCOp(f61b1fa8d7444907b15bf28d5e0b97b6): 482 bytes on disk
I20260812 06:20:23.590721 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: UndoDeltaBlockGCOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":67,"lbm_reads_lt_1ms":4}
I20260812 06:20:23.591213 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=14.095187
I20260812 06:20:23.636207 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.045s	user 0.040s	sys 0.000s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":18769,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:23.636709 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=3.181125
I20260812 06:20:23.651456 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.015s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":3948,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:23.651893 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=2.188937
I20260812 06:20:23.667713 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.016s	user 0.008s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3171,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:23.668212 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling MajorDeltaCompactionOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=1.000000
I20260812 06:20:23.856355 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: MajorDeltaCompactionOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.188s	user 0.120s	sys 0.068s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918203,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":561,"lbm_read_time_us":12915,"lbm_reads_lt_1ms":673,"lbm_write_time_us":31704,"lbm_writes_lt_1ms":643,"mutex_wait_us":276,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":8448,"update_count":3000}
I20260812 06:20:23.856884 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=14.095187
I20260812 06:20:23.911738 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.055s	user 0.009s	sys 0.043s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":20381,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:23.912238 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=2.188937
I20260812 06:20:23.926924 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.015s	user 0.001s	sys 0.012s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5770,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.927357 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling MajorDeltaCompactionOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=1.000000
I20260812 06:20:24.106827 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: MajorDeltaCompactionOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.179s	user 0.122s	sys 0.043s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815680,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":466,"lbm_read_time_us":11186,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25688,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2500}
I20260812 06:20:24.109766 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=14.095187
I20260812 06:20:24.158279 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.048s	user 0.023s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21905,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:24.158749 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=2.188937
I20260812 06:20:24.168397 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.009s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3729,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.169062 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling MajorDeltaCompactionOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=1.000000
I20260812 06:20:24.337679 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: MajorDeltaCompactionOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.168s	user 0.108s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":855,"lbm_read_time_us":9081,"lbm_reads_lt_1ms":572,"lbm_write_time_us":24794,"lbm_writes_lt_1ms":543,"mutex_wait_us":272,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6528,"update_count":2500}
I20260812 06:20:24.338196 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=14.095187
I20260812 06:20:24.385071 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.047s	user 0.029s	sys 0.009s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":17567,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:24.385635 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=2.188937
I20260812 06:20:24.395593 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3720,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.396238 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling MajorDeltaCompactionOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=1.000000
I20260812 06:20:24.540287 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: MajorDeltaCompactionOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.144s	user 0.106s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":729,"lbm_read_time_us":8945,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26942,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:20:24.541018 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=10.126437
I20260812 06:20:24.571141 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.030s	user 0.028s	sys 0.000s Metrics: {"bytes_written":12430563,"delete_count":0,"lbm_write_time_us":12449,"lbm_writes_lt_1ms":306,"mutex_wait_us":106,"reinsert_count":0,"update_count":1515}
I20260812 06:20:24.571656 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=2.188937
I20260812 06:20:24.585147 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.013s	user 0.000s	sys 0.011s Metrics: {"bytes_written":3979584,"delete_count":0,"lbm_write_time_us":4807,"lbm_writes_lt_1ms":100,"reinsert_count":0,"update_count":485}
I20260812 06:20:24.585708 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling MajorDeltaCompactionOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=1.000000
I20260812 06:20:24.702428 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: MajorDeltaCompactionOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.117s	user 0.091s	sys 0.026s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713270,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":231,"lbm_read_time_us":8856,"lbm_reads_lt_1ms":472,"lbm_write_time_us":19798,"lbm_writes_lt_1ms":443,"mutex_wait_us":37,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2000}
I20260812 06:20:24.702952 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=10.126437
I20260812 06:20:24.746152 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.043s	user 0.020s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13537,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:24.746711 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=2.188937
I20260812 06:20:24.761173 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.014s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5221,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.761719 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling FlushMRSOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=1.000000
I20260812 06:20:24.787994 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: FlushMRSOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.026s	user 0.024s	sys 0.000s Metrics: {"bytes_written":1193507,"cfile_init":1,"dirs.queue_time_us":48,"dirs.run_cpu_time_us":199,"dirs.run_wall_time_us":1206,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1470,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:24.788580 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling LogGCOp(f61b1fa8d7444907b15bf28d5e0b97b6): free 117302596 bytes of WAL
I20260812 06:20:24.788779 30513 log_reader.cc:385] T f61b1fa8d7444907b15bf28d5e0b97b6: removed 12 log segments from log reader
I20260812 06:20:24.788825 30513 log.cc:1079] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/f61b1fa8d7444907b15bf28d5e0b97b6/wal-000000016 (ops 75-79)
I20260812 06:20:24.788852 30513 log.cc:1079] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/f61b1fa8d7444907b15bf28d5e0b97b6/wal-000000017 (ops 80-84)
I20260812 06:20:24.788883 30513 log.cc:1079] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/f61b1fa8d7444907b15bf28d5e0b97b6/wal-000000018 (ops 85-89)
I20260812 06:20:24.788916 30513 log.cc:1079] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/f61b1fa8d7444907b15bf28d5e0b97b6/wal-000000019 (ops 90-94)
I20260812 06:20:24.788941 30513 log.cc:1079] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/f61b1fa8d7444907b15bf28d5e0b97b6/wal-000000020 (ops 95-99)
I20260812 06:20:24.788975 30513 log.cc:1079] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/f61b1fa8d7444907b15bf28d5e0b97b6/wal-000000021 (ops 100-104)
I20260812 06:20:24.789007 30513 log.cc:1079] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/f61b1fa8d7444907b15bf28d5e0b97b6/wal-000000022 (ops 105-108)
I20260812 06:20:24.789039 30513 log.cc:1079] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/f61b1fa8d7444907b15bf28d5e0b97b6/wal-000000023 (ops 109-113)
I20260812 06:20:24.789072 30513 log.cc:1079] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/f61b1fa8d7444907b15bf28d5e0b97b6/wal-000000024 (ops 114-118)
I20260812 06:20:24.789104 30513 log.cc:1079] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/f61b1fa8d7444907b15bf28d5e0b97b6/wal-000000025 (ops 119-122)
I20260812 06:20:24.789136 30513 log.cc:1079] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/f61b1fa8d7444907b15bf28d5e0b97b6/wal-000000026 (ops 123-127)
I20260812 06:20:24.789168 30513 log.cc:1079] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/f61b1fa8d7444907b15bf28d5e0b97b6/wal-000000027 (ops 128-132)
I20260812 06:20:24.809830 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: LogGCOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.021s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:20:24.810175 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=3.181125
I20260812 06:20:24.825994 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.016s	user 0.008s	sys 0.002s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4240,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:24.826368 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling UndoDeltaBlockGCOp(f61b1fa8d7444907b15bf28d5e0b97b6): 463 bytes on disk
I20260812 06:20:24.826702 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: UndoDeltaBlockGCOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:20:24.827234 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=2.188937
I20260812 06:20:24.836001 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.009s	user 0.000s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3321,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:24.836489 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling MajorDeltaCompactionOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=1.000000
I20260812 06:20:25.000154 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: MajorDeltaCompactionOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.163s	user 0.134s	sys 0.028s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918322,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":488,"lbm_read_time_us":12604,"lbm_reads_lt_1ms":674,"lbm_write_time_us":32326,"lbm_writes_lt_1ms":643,"mutex_wait_us":291,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":19840,"thread_start_us":71,"threads_started":1,"update_count":3000}
I20260812 06:20:25.000727 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=14.095187
I20260812 06:20:25.042975 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.042s	user 0.031s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17275,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:25.043488 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=2.188937
I20260812 06:20:25.056571 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.013s	user 0.000s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5283,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.057034 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling MajorDeltaCompactionOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=1.000000
I20260812 06:20:25.203593 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: MajorDeltaCompactionOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.146s	user 0.097s	sys 0.035s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":200,"lbm_read_time_us":9189,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25762,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5760,"update_count":2500}
I20260812 06:20:25.204324 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=14.095187
I20260812 06:20:25.255506 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.051s	user 0.029s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17068,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:25.256052 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=2.188937
I20260812 06:20:25.266580 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.010s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3664,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.267058 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling MajorDeltaCompactionOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=1.000000
I20260812 06:20:25.438541 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: MajorDeltaCompactionOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.171s	user 0.097s	sys 0.070s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":224,"lbm_read_time_us":10455,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27761,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":25728,"update_count":2500}
I20260812 06:20:25.439071 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=14.095187
I20260812 06:20:25.479497 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.040s	user 0.026s	sys 0.012s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":18004,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:25.479964 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling MajorDeltaCompactionOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=1.000000
I20260812 06:20:25.611037 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: MajorDeltaCompactionOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.131s	user 0.109s	sys 0.016s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713155,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":155,"lbm_read_time_us":8496,"lbm_reads_lt_1ms":467,"lbm_write_time_us":18583,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2000}
I20260812 06:20:25.611539 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=11.118625
I20260812 06:20:25.639046 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.027s	user 0.010s	sys 0.016s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":11659,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:25.639519 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=2.188937
I20260812 06:20:25.655761 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.016s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5326,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:25.656399 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling MajorDeltaCompactionOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=1.000000
I20260812 06:20:25.778540 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: MajorDeltaCompactionOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.122s	user 0.087s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713265,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":663,"lbm_read_time_us":7856,"lbm_reads_lt_1ms":464,"lbm_write_time_us":22873,"lbm_writes_lt_1ms":443,"mutex_wait_us":276,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5504,"update_count":2000}
I20260812 06:20:25.779022 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=10.126437
I20260812 06:20:25.816943 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.038s	user 0.010s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16026,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:25.817523 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=2.188937
I20260812 06:20:25.831970 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.014s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5069,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.832587 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling MajorDeltaCompactionOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=1.000000
I20260812 06:20:25.944865 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: MajorDeltaCompactionOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.112s	user 0.088s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":142,"lbm_read_time_us":7830,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21524,"lbm_writes_lt_1ms":443,"mutex_wait_us":40,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5760,"update_count":2000}
I20260812 06:20:25.945420 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=10.126437
I20260812 06:20:25.986264 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.041s	user 0.019s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13963,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:25.986758 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=2.188937
I20260812 06:20:25.996349 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3546,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.997008 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling FlushMRSOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=1.000000
I20260812 06:20:26.023397 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: FlushMRSOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.026s	user 0.019s	sys 0.004s Metrics: {"bytes_written":1152512,"cfile_init":1,"dirs.queue_time_us":52,"dirs.run_cpu_time_us":172,"dirs.run_wall_time_us":1205,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1257,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:26.024075 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling LogGCOp(f61b1fa8d7444907b15bf28d5e0b97b6): free 112239554 bytes of WAL
I20260812 06:20:26.024292 30513 log_reader.cc:385] T f61b1fa8d7444907b15bf28d5e0b97b6: removed 11 log segments from log reader
I20260812 06:20:26.024353 30513 log.cc:1079] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/f61b1fa8d7444907b15bf28d5e0b97b6/wal-000000028 (ops 133-137)
I20260812 06:20:26.024391 30513 log.cc:1079] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/f61b1fa8d7444907b15bf28d5e0b97b6/wal-000000029 (ops 138-142)
I20260812 06:20:26.024415 30513 log.cc:1079] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/f61b1fa8d7444907b15bf28d5e0b97b6/wal-000000030 (ops 143-147)
I20260812 06:20:26.024439 30513 log.cc:1079] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/f61b1fa8d7444907b15bf28d5e0b97b6/wal-000000031 (ops 148-152)
I20260812 06:20:26.024471 30513 log.cc:1079] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/f61b1fa8d7444907b15bf28d5e0b97b6/wal-000000032 (ops 153-157)
I20260812 06:20:26.024500 30513 log.cc:1079] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/f61b1fa8d7444907b15bf28d5e0b97b6/wal-000000033 (ops 158-162)
I20260812 06:20:26.024521 30513 log.cc:1079] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/f61b1fa8d7444907b15bf28d5e0b97b6/wal-000000034 (ops 163-167)
I20260812 06:20:26.024549 30513 log.cc:1079] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/f61b1fa8d7444907b15bf28d5e0b97b6/wal-000000035 (ops 168-172)
I20260812 06:20:26.024581 30513 log.cc:1079] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/f61b1fa8d7444907b15bf28d5e0b97b6/wal-000000036 (ops 173-176)
I20260812 06:20:26.024612 30513 log.cc:1079] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/f61b1fa8d7444907b15bf28d5e0b97b6/wal-000000037 (ops 177-181)
I20260812 06:20:26.024641 30513 log.cc:1079] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/f61b1fa8d7444907b15bf28d5e0b97b6/wal-000000038 (ops 182-186)
I20260812 06:20:26.048386 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: LogGCOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.024s	user 0.002s	sys 0.019s Metrics: {}
I20260812 06:20:26.048847 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=3.181125
I20260812 06:20:26.064181 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.015s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4358,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:26.064658 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling LogGCOp(f61b1fa8d7444907b15bf28d5e0b97b6): free 11564891 bytes of WAL
I20260812 06:20:26.064862 30513 log_reader.cc:385] T f61b1fa8d7444907b15bf28d5e0b97b6: removed 1 log segments from log reader
I20260812 06:20:26.064908 30513 log.cc:1079] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7: Deleting log segment in path: /tmp/dist-test-taskrZkhV3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616667027-30017-0/minicluster-data/ts-0-root/wals/f61b1fa8d7444907b15bf28d5e0b97b6/wal-000000039 (ops 187-190)
I20260812 06:20:26.066617 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: LogGCOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.002s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:20:26.066933 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling UndoDeltaBlockGCOp(f61b1fa8d7444907b15bf28d5e0b97b6): 447 bytes on disk
I20260812 06:20:26.067319 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: UndoDeltaBlockGCOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4}
I20260812 06:20:26.067855 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=2.188937
I20260812 06:20:26.077611 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.010s	user 0.005s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3336,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:26.078202 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling MajorDeltaCompactionOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=1.000000
I20260812 06:20:26.258004 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: MajorDeltaCompactionOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.180s	user 0.134s	sys 0.044s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918321,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":613,"lbm_read_time_us":12995,"lbm_reads_lt_1ms":674,"lbm_write_time_us":38150,"lbm_writes_lt_1ms":643,"mutex_wait_us":316,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3968,"thread_start_us":70,"threads_started":1,"update_count":3000}
I20260812 06:20:26.258549 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=14.095187
I20260812 06:20:26.304849 30017 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.488s	user 1.665s	sys 0.139s
I20260812 06:20:26.307736 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.049s	user 0.026s	sys 0.013s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":17954,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:26.308259 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=2.188937
I20260812 06:20:26.317924 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: FlushDeltaMemStoresOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.009s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4086,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.318282 30621 maintenance_manager.cc:419] P c74a70cc44994e0fba80213b6b87baa7: Scheduling MajorDeltaCompactionOp(f61b1fa8d7444907b15bf28d5e0b97b6): perf score=1.000000
I20260812 06:20:26.344004 30017 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.039s	user 0.001s	sys 0.000s
I20260812 06:20:26.344463 30017 tablet_server.cc:179] TabletServer@127.29.80.65:0 shutting down...
I20260812 06:20:26.421170 30513 maintenance_manager.cc:643] P c74a70cc44994e0fba80213b6b87baa7: MajorDeltaCompactionOp(f61b1fa8d7444907b15bf28d5e0b97b6) complete. Timing: real 0.103s	user 0.079s	sys 0.024s Metrics: {"cfile_cache_hit":401,"cfile_cache_hit_bytes":16409768,"cfile_cache_miss":131,"cfile_cache_miss_bytes":8405915,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":283,"lbm_read_time_us":3099,"lbm_reads_lt_1ms":163,"lbm_write_time_us":22821,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":19200,"update_count":2500}
I20260812 06:20:26.421831 30017 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:26.422022 30017 tablet_replica.cc:333] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7: stopping tablet replica
I20260812 06:20:26.422171 30017 raft_consensus.cc:2243] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:26.422320 30017 raft_consensus.cc:2272] T f61b1fa8d7444907b15bf28d5e0b97b6 P c74a70cc44994e0fba80213b6b87baa7 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:26.425485 30017 tablet_server.cc:196] TabletServer@127.29.80.65:0 shutdown complete.
I20260812 06:20:26.465847 30017 master.cc:562] Master@127.29.80.126:39021 shutting down...
I20260812 06:20:26.468761 30017 raft_consensus.cc:2243] T 00000000000000000000000000000000 P e2577883c2234dd09870a33e82ede8f3 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:26.468915 30017 raft_consensus.cc:2272] T 00000000000000000000000000000000 P e2577883c2234dd09870a33e82ede8f3 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:26.468983 30017 tablet_replica.cc:333] T 00000000000000000000000000000000 P e2577883c2234dd09870a33e82ede8f3: stopping tablet replica
I20260812 06:20:26.480906 30017 master.cc:584] Master@127.29.80.126:39021 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (4885 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (9873 ms total)

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