[==========] 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:18:19.913430 21365 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.20.221.126:42403
I20260812 06:18:19.914423 21365 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:18:19.914996 21365 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:19.920864 21373 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:18:19.920895 21374 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:18:19.920895 21377 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:18:19.921216 21365 server_base.cc:1061] running on GCE node
I20260812 06:18:19.921679 21365 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:19.921775 21365 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:18:19.921818 21365 hybrid_clock.cc:648] HybridClock initialized: now 1786515499921815 us; error 0 us; skew 500 ppm
I20260812 06:18:19.923436 21365 webserver.cc:533] Webserver started at http://127.20.221.126:35073/ using document root <none> and password file <none>
I20260812 06:18:19.923960 21365 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:19.924022 21365 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:19.924245 21365 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:19.925763 21365 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515499903233-21365-0/minicluster-data/master-0-root/instance:
uuid: "760be29ac4464673b39bea1d3c6f4c6f"
format_stamp: "Formatted at 2026-08-12 06:18:19 on dist-test-slave-jlzn"
I20260812 06:18:19.928968 21365 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:18:19.930842 21382 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:18:19.931738 21365 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:19.931856 21365 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515499903233-21365-0/minicluster-data/master-0-root
uuid: "760be29ac4464673b39bea1d3c6f4c6f"
format_stamp: "Formatted at 2026-08-12 06:18:19 on dist-test-slave-jlzn"
I20260812 06:18:19.931943 21365 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515499903233-21365-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515499903233-21365-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515499903233-21365-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:18:19.947780 21365 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:19.948423 21365 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:18:19.948577 21365 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:19.955446 21365 rpc_server.cc:307] RPC server started. Bound to: 127.20.221.126:42403
I20260812 06:18:19.955480 21468 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.20.221.126:42403 every 8 connection(s)
I20260812 06:18:19.957562 21469 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:18:19.962778 21469 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 760be29ac4464673b39bea1d3c6f4c6f: Bootstrap starting.
I20260812 06:18:19.964979 21469 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 760be29ac4464673b39bea1d3c6f4c6f: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:19.965827 21469 log.cc:826] T 00000000000000000000000000000000 P 760be29ac4464673b39bea1d3c6f4c6f: Log is configured to *not* fsync() on all Append() calls
I20260812 06:18:19.967340 21469 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 760be29ac4464673b39bea1d3c6f4c6f: No bootstrap required, opened a new log
I20260812 06:18:19.969982 21469 raft_consensus.cc:359] T 00000000000000000000000000000000 P 760be29ac4464673b39bea1d3c6f4c6f [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "760be29ac4464673b39bea1d3c6f4c6f" member_type: VOTER }
I20260812 06:18:19.970130 21469 raft_consensus.cc:385] T 00000000000000000000000000000000 P 760be29ac4464673b39bea1d3c6f4c6f [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:19.970196 21469 raft_consensus.cc:740] T 00000000000000000000000000000000 P 760be29ac4464673b39bea1d3c6f4c6f [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 760be29ac4464673b39bea1d3c6f4c6f, State: Initialized, Role: FOLLOWER
I20260812 06:18:19.970712 21469 consensus_queue.cc:260] T 00000000000000000000000000000000 P 760be29ac4464673b39bea1d3c6f4c6f [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: "760be29ac4464673b39bea1d3c6f4c6f" member_type: VOTER }
I20260812 06:18:19.970851 21469 raft_consensus.cc:399] T 00000000000000000000000000000000 P 760be29ac4464673b39bea1d3c6f4c6f [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:19.970914 21469 raft_consensus.cc:493] T 00000000000000000000000000000000 P 760be29ac4464673b39bea1d3c6f4c6f [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:19.971024 21469 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 760be29ac4464673b39bea1d3c6f4c6f [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:19.971728 21469 raft_consensus.cc:515] T 00000000000000000000000000000000 P 760be29ac4464673b39bea1d3c6f4c6f [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "760be29ac4464673b39bea1d3c6f4c6f" member_type: VOTER }
I20260812 06:18:19.972124 21469 leader_election.cc:304] T 00000000000000000000000000000000 P 760be29ac4464673b39bea1d3c6f4c6f [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: 760be29ac4464673b39bea1d3c6f4c6f; no voters: 
I20260812 06:18:19.972384 21469 leader_election.cc:290] T 00000000000000000000000000000000 P 760be29ac4464673b39bea1d3c6f4c6f [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:19.972494 21472 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 760be29ac4464673b39bea1d3c6f4c6f [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:19.972715 21472 raft_consensus.cc:697] T 00000000000000000000000000000000 P 760be29ac4464673b39bea1d3c6f4c6f [term 1 LEADER]: Becoming Leader. State: Replica: 760be29ac4464673b39bea1d3c6f4c6f, State: Running, Role: LEADER
I20260812 06:18:19.973042 21472 consensus_queue.cc:237] T 00000000000000000000000000000000 P 760be29ac4464673b39bea1d3c6f4c6f [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: "760be29ac4464673b39bea1d3c6f4c6f" member_type: VOTER }
I20260812 06:18:19.973204 21469 sys_catalog.cc:565] T 00000000000000000000000000000000 P 760be29ac4464673b39bea1d3c6f4c6f [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:19.974732 21474 sys_catalog.cc:455] T 00000000000000000000000000000000 P 760be29ac4464673b39bea1d3c6f4c6f [sys.catalog]: SysCatalogTable state changed. Reason: New leader 760be29ac4464673b39bea1d3c6f4c6f. Latest consensus state: current_term: 1 leader_uuid: "760be29ac4464673b39bea1d3c6f4c6f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "760be29ac4464673b39bea1d3c6f4c6f" member_type: VOTER } }
I20260812 06:18:19.974727 21473 sys_catalog.cc:455] T 00000000000000000000000000000000 P 760be29ac4464673b39bea1d3c6f4c6f [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "760be29ac4464673b39bea1d3c6f4c6f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "760be29ac4464673b39bea1d3c6f4c6f" member_type: VOTER } }
I20260812 06:18:19.974865 21474 sys_catalog.cc:458] T 00000000000000000000000000000000 P 760be29ac4464673b39bea1d3c6f4c6f [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:19.974882 21473 sys_catalog.cc:458] T 00000000000000000000000000000000 P 760be29ac4464673b39bea1d3c6f4c6f [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:19.975194 21491 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:19.975278 21365 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:19.977419 21491 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:19.981812 21491 catalog_manager.cc:1383] Generated new cluster ID: 39b5ff5fed3e4f6081d91e384cd11150
I20260812 06:18:19.981861 21491 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:19.991586 21491 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:19.992321 21491 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:20.004902 21491 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 760be29ac4464673b39bea1d3c6f4c6f: Generated new TSK 0
I20260812 06:18:20.005477 21491 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:20.007670 21365 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:20.010186 21500 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:18:20.010242 21503 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:18:20.010186 21501 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:18:20.010546 21365 server_base.cc:1061] running on GCE node
I20260812 06:18:20.010708 21365 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:20.010749 21365 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:18:20.010763 21365 hybrid_clock.cc:648] HybridClock initialized: now 1786515500010764 us; error 0 us; skew 500 ppm
I20260812 06:18:20.011592 21365 webserver.cc:533] Webserver started at http://127.20.221.65:45961/ using document root <none> and password file <none>
I20260812 06:18:20.011757 21365 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:20.011833 21365 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:20.011911 21365 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:20.012247 21365 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515499903233-21365-0/minicluster-data/ts-0-root/instance:
uuid: "8d765999e3ad4b97b48d0948b2fb171a"
format_stamp: "Formatted at 2026-08-12 06:18:20 on dist-test-slave-jlzn"
I20260812 06:18:20.013594 21365 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:18:20.014528 21513 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:18:20.014745 21365 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:18:20.014812 21365 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515499903233-21365-0/minicluster-data/ts-0-root
uuid: "8d765999e3ad4b97b48d0948b2fb171a"
format_stamp: "Formatted at 2026-08-12 06:18:20 on dist-test-slave-jlzn"
I20260812 06:18:20.014878 21365 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515499903233-21365-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515499903233-21365-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515499903233-21365-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:18:20.056030 21365 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:20.056483 21365 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:20.056982 21365 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:20.057917 21365 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:20.057974 21365 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:20.058020 21365 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:20.058049 21365 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:20.064234 21365 rpc_server.cc:307] RPC server started. Bound to: 127.20.221.65:36549
I20260812 06:18:20.064277 21616 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.20.221.65:36549 every 8 connection(s)
I20260812 06:18:20.076936 21617 heartbeater.cc:344] Connected to a master server at 127.20.221.126:42403
I20260812 06:18:20.077160 21617 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:20.077556 21617 heartbeater.cc:507] Master 127.20.221.126:42403 requested a full tablet report, sending...
I20260812 06:18:20.078926 21409 ts_manager.cc:194] Registered new tserver with Master: 8d765999e3ad4b97b48d0948b2fb171a (127.20.221.65:36549)
I20260812 06:18:20.079169 21365 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.014368199s
I20260812 06:18:20.080353 21409 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:32814
I20260812 06:18:20.087966 21409 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:32828:
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:18:20.101944 21563 tablet_service.cc:1511] Processing CreateTablet for tablet 415eaa7047df4c18a331111e460c35ca (DEFAULT_TABLE table=heavy-update-compaction-test [id=dafdcdf046db4227afdd4bb5b05985ec]), partition=
I20260812 06:18:20.102409 21563 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 415eaa7047df4c18a331111e460c35ca. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:20.104815 21634 tablet_bootstrap.cc:492] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a: Bootstrap starting.
I20260812 06:18:20.105603 21634 tablet_bootstrap.cc:654] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:20.106932 21634 tablet_bootstrap.cc:492] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a: No bootstrap required, opened a new log
I20260812 06:18:20.107013 21634 ts_tablet_manager.cc:1403] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:20.107508 21634 raft_consensus.cc:359] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8d765999e3ad4b97b48d0948b2fb171a" member_type: VOTER last_known_addr { host: "127.20.221.65" port: 36549 } }
I20260812 06:18:20.107606 21634 raft_consensus.cc:385] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:20.107638 21634 raft_consensus.cc:740] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 8d765999e3ad4b97b48d0948b2fb171a, State: Initialized, Role: FOLLOWER
I20260812 06:18:20.107872 21634 consensus_queue.cc:260] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a [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: "8d765999e3ad4b97b48d0948b2fb171a" member_type: VOTER last_known_addr { host: "127.20.221.65" port: 36549 } }
I20260812 06:18:20.107971 21634 raft_consensus.cc:399] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:20.108000 21634 raft_consensus.cc:493] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:20.108048 21634 raft_consensus.cc:3060] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:20.108728 21634 raft_consensus.cc:515] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8d765999e3ad4b97b48d0948b2fb171a" member_type: VOTER last_known_addr { host: "127.20.221.65" port: 36549 } }
I20260812 06:18:20.108839 21634 leader_election.cc:304] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a [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: 8d765999e3ad4b97b48d0948b2fb171a; no voters: 
I20260812 06:18:20.109015 21634 leader_election.cc:290] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:20.109136 21636 raft_consensus.cc:2804] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:20.109328 21634 ts_tablet_manager.cc:1434] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:20.109406 21636 raft_consensus.cc:697] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a [term 1 LEADER]: Becoming Leader. State: Replica: 8d765999e3ad4b97b48d0948b2fb171a, State: Running, Role: LEADER
I20260812 06:18:20.109530 21617 heartbeater.cc:499] Master 127.20.221.126:42403 was elected leader, sending a full tablet report...
I20260812 06:18:20.109555 21636 consensus_queue.cc:237] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a [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: "8d765999e3ad4b97b48d0948b2fb171a" member_type: VOTER last_known_addr { host: "127.20.221.65" port: 36549 } }
I20260812 06:18:20.112092 21409 catalog_manager.cc:5719] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a reported cstate change: term changed from 0 to 1, leader changed from <none> to 8d765999e3ad4b97b48d0948b2fb171a (127.20.221.65). New cstate: current_term: 1 leader_uuid: "8d765999e3ad4b97b48d0948b2fb171a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8d765999e3ad4b97b48d0948b2fb171a" member_type: VOTER last_known_addr { host: "127.20.221.65" port: 36549 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:20.172495 21365 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.054s	user 0.009s	sys 0.020s
I20260812 06:18:20.315229 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling FlushMRSOp(415eaa7047df4c18a331111e460c35ca): perf score=21.039315
I20260812 06:18:20.512750 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: FlushMRSOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.197s	user 0.156s	sys 0.039s Metrics: {"bytes_written":16409902,"cfile_init":1,"compiler_manager_pool.queue_time_us":174,"delete_count":0,"dirs.queue_time_us":75,"dirs.run_cpu_time_us":196,"dirs.run_wall_time_us":958,"drs_written":1,"lbm_read_time_us":74,"lbm_reads_lt_1ms":4,"lbm_write_time_us":51169,"lbm_writes_lt_1ms":957,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"thread_start_us":96,"threads_started":1,"update_count":2000}
I20260812 06:18:20.513942 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling LogGCOp(415eaa7047df4c18a331111e460c35ca): free 20743880 bytes of WAL
I20260812 06:18:20.514271 21522 log_reader.cc:385] T 415eaa7047df4c18a331111e460c35ca: removed 2 log segments from log reader
I20260812 06:18:20.514356 21522 log.cc:1079] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/415eaa7047df4c18a331111e460c35ca/wal-000000001 (ops 1-6)
I20260812 06:18:20.514423 21522 log.cc:1079] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/415eaa7047df4c18a331111e460c35ca/wal-000000002 (ops 7-11)
I20260812 06:18:20.519251 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: LogGCOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.005s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:18:20.519635 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling UndoDeltaBlockGCOp(415eaa7047df4c18a331111e460c35ca): 20513817 bytes on disk
I20260812 06:18:20.520382 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: UndoDeltaBlockGCOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":75,"lbm_reads_lt_1ms":4}
I20260812 06:18:20.520862 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca): perf score=2.188937
I20260812 06:18:20.546020 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.025s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4934,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:20.546495 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca): perf score=2.188937
I20260812 06:18:20.560362 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.014s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5061,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:20.560884 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling MajorDeltaCompactionOp(415eaa7047df4c18a331111e460c35ca): perf score=1.000000
I20260812 06:18:20.741314 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: MajorDeltaCompactionOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.180s	user 0.113s	sys 0.067s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918215,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":897,"lbm_read_time_us":10710,"lbm_reads_lt_1ms":669,"lbm_write_time_us":28373,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3584,"thread_start_us":304,"threads_started":5,"update_count":3000}
I20260812 06:18:20.741905 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca): perf score=14.095187
I20260812 06:18:20.789150 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.047s	user 0.029s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20459,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:20.789618 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling MajorDeltaCompactionOp(415eaa7047df4c18a331111e460c35ca): perf score=1.000000
I20260812 06:18:20.933522 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: MajorDeltaCompactionOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.144s	user 0.106s	sys 0.036s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713152,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":538,"lbm_read_time_us":9639,"lbm_reads_lt_1ms":463,"lbm_write_time_us":23446,"lbm_writes_lt_1ms":443,"mutex_wait_us":303,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10624,"update_count":2000}
I20260812 06:18:20.933998 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca): perf score=11.118625
I20260812 06:18:20.966917 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.033s	user 0.017s	sys 0.013s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":13234,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:20.967521 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca): perf score=2.188937
I20260812 06:18:20.981737 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.014s	user 0.004s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4598,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:20.982266 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling MajorDeltaCompactionOp(415eaa7047df4c18a331111e460c35ca): perf score=1.000000
I20260812 06:18:21.091914 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: MajorDeltaCompactionOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.109s	user 0.075s	sys 0.033s 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":784,"lbm_read_time_us":7066,"lbm_reads_lt_1ms":464,"lbm_write_time_us":20585,"lbm_writes_lt_1ms":443,"mutex_wait_us":267,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:21.092438 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca): perf score=10.126437
I20260812 06:18:21.126192 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.034s	user 0.016s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13434,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:21.126613 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca): perf score=2.188937
I20260812 06:18:21.136073 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.009s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3539,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:21.136579 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling MajorDeltaCompactionOp(415eaa7047df4c18a331111e460c35ca): perf score=1.000000
I20260812 06:18:21.252113 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: MajorDeltaCompactionOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.115s	user 0.095s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":136,"lbm_read_time_us":7473,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21350,"lbm_writes_lt_1ms":443,"mutex_wait_us":25,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8576,"update_count":2000}
I20260812 06:18:21.252578 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca): perf score=10.126437
I20260812 06:18:21.295287 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.043s	user 0.022s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16115,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:21.295765 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca): perf score=2.188937
I20260812 06:18:21.305178 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.009s	user 0.003s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3501,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:21.305653 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling MajorDeltaCompactionOp(415eaa7047df4c18a331111e460c35ca): perf score=1.000000
I20260812 06:18:21.420511 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: MajorDeltaCompactionOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.115s	user 0.091s	sys 0.023s 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":158,"lbm_read_time_us":7873,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20425,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2000}
I20260812 06:18:21.420980 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca): perf score=10.126437
I20260812 06:18:21.465826 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.045s	user 0.030s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14197,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:21.466387 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca): perf score=2.188937
I20260812 06:18:21.480969 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.014s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5516,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:21.481406 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling MajorDeltaCompactionOp(415eaa7047df4c18a331111e460c35ca): perf score=1.000000
I20260812 06:18:21.616101 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: MajorDeltaCompactionOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.135s	user 0.098s	sys 0.036s 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":596,"lbm_read_time_us":10122,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22867,"lbm_writes_lt_1ms":443,"mutex_wait_us":73,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":45056,"update_count":2000}
I20260812 06:18:21.616636 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca): perf score=10.126437
I20260812 06:18:21.656483 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.040s	user 0.030s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14623,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:21.656987 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca): perf score=2.188937
I20260812 06:18:21.671604 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.014s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5246,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:21.672111 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling FlushMRSOp(415eaa7047df4c18a331111e460c35ca): perf score=1.000000
I20260812 06:18:21.698997 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: FlushMRSOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.027s	user 0.024s	sys 0.001s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":73,"dirs.run_cpu_time_us":214,"dirs.run_wall_time_us":1218,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1397,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:18:21.699780 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling LogGCOp(415eaa7047df4c18a331111e460c35ca): free 121006425 bytes of WAL
I20260812 06:18:21.700007 21522 log_reader.cc:385] T 415eaa7047df4c18a331111e460c35ca: removed 12 log segments from log reader
I20260812 06:18:21.700054 21522 log.cc:1079] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/415eaa7047df4c18a331111e460c35ca/wal-000000003 (ops 12-16)
I20260812 06:18:21.700080 21522 log.cc:1079] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/415eaa7047df4c18a331111e460c35ca/wal-000000004 (ops 17-21)
I20260812 06:18:21.700110 21522 log.cc:1079] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/415eaa7047df4c18a331111e460c35ca/wal-000000005 (ops 22-26)
I20260812 06:18:21.700141 21522 log.cc:1079] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/415eaa7047df4c18a331111e460c35ca/wal-000000006 (ops 27-31)
I20260812 06:18:21.700173 21522 log.cc:1079] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/415eaa7047df4c18a331111e460c35ca/wal-000000007 (ops 32-36)
I20260812 06:18:21.700215 21522 log.cc:1079] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/415eaa7047df4c18a331111e460c35ca/wal-000000008 (ops 37-40)
I20260812 06:18:21.700246 21522 log.cc:1079] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/415eaa7047df4c18a331111e460c35ca/wal-000000009 (ops 41-45)
I20260812 06:18:21.700276 21522 log.cc:1079] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/415eaa7047df4c18a331111e460c35ca/wal-000000010 (ops 46-50)
I20260812 06:18:21.700307 21522 log.cc:1079] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/415eaa7047df4c18a331111e460c35ca/wal-000000011 (ops 51-55)
I20260812 06:18:21.700337 21522 log.cc:1079] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/415eaa7047df4c18a331111e460c35ca/wal-000000012 (ops 56-60)
I20260812 06:18:21.700367 21522 log.cc:1079] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/415eaa7047df4c18a331111e460c35ca/wal-000000013 (ops 61-65)
I20260812 06:18:21.700397 21522 log.cc:1079] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/415eaa7047df4c18a331111e460c35ca/wal-000000014 (ops 66-70)
I20260812 06:18:21.720688 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: LogGCOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.021s	user 0.000s	sys 0.020s Metrics: {}
I20260812 06:18:21.721077 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca): perf score=3.181125
I20260812 06:18:21.745574 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.024s	user 0.010s	sys 0.011s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":6497,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:21.746006 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling UndoDeltaBlockGCOp(415eaa7047df4c18a331111e460c35ca): 472 bytes on disk
I20260812 06:18:21.746392 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: UndoDeltaBlockGCOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4}
I20260812 06:18:21.746846 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca): perf score=2.188937
I20260812 06:18:21.755733 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.009s	user 0.007s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3234,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:21.756138 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling MajorDeltaCompactionOp(415eaa7047df4c18a331111e460c35ca): perf score=1.000000
I20260812 06:18:21.946429 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: MajorDeltaCompactionOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.190s	user 0.129s	sys 0.048s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918323,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1000,"lbm_read_time_us":12536,"lbm_reads_lt_1ms":674,"lbm_write_time_us":30253,"lbm_writes_lt_1ms":643,"mutex_wait_us":77,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":76,"threads_started":1,"update_count":3000}
I20260812 06:18:21.947157 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca): perf score=14.095187
I20260812 06:18:22.002035 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.055s	user 0.026s	sys 0.026s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":19709,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:22.002673 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca): perf score=2.188937
I20260812 06:18:22.013041 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3507,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:22.013597 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling MajorDeltaCompactionOp(415eaa7047df4c18a331111e460c35ca): perf score=1.000000
I20260812 06:18:22.189540 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: MajorDeltaCompactionOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.175s	user 0.115s	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":267,"lbm_read_time_us":12103,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28246,"lbm_writes_lt_1ms":543,"mutex_wait_us":50,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:18:22.190037 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca): perf score=14.095187
I20260812 06:18:22.235880 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.045s	user 0.030s	sys 0.015s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19688,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:22.236353 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca): perf score=2.188937
I20260812 06:18:22.252167 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.016s	user 0.000s	sys 0.015s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3703,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:22.252636 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling MajorDeltaCompactionOp(415eaa7047df4c18a331111e460c35ca): perf score=1.000000
I20260812 06:18:22.421702 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: MajorDeltaCompactionOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.169s	user 0.102s	sys 0.063s 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":735,"lbm_read_time_us":11855,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27305,"lbm_writes_lt_1ms":543,"mutex_wait_us":56,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2500}
I20260812 06:18:22.422895 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca): perf score=11.118625
I20260812 06:18:22.457630 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.035s	user 0.025s	sys 0.008s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14097,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:22.458254 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca): perf score=2.188937
I20260812 06:18:22.471418 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.013s	user 0.003s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4250,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:22.471928 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling MajorDeltaCompactionOp(415eaa7047df4c18a331111e460c35ca): perf score=1.000000
I20260812 06:18:22.590095 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: MajorDeltaCompactionOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.118s	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":997,"lbm_read_time_us":7035,"lbm_reads_lt_1ms":464,"lbm_write_time_us":21939,"lbm_writes_lt_1ms":443,"mutex_wait_us":286,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4352,"update_count":2000}
I20260812 06:18:22.593760 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca): perf score=11.118625
I20260812 06:18:22.627935 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.034s	user 0.021s	sys 0.013s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":14489,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:22.628417 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca): perf score=2.188937
I20260812 06:18:22.639614 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3839,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:22.640110 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling MajorDeltaCompactionOp(415eaa7047df4c18a331111e460c35ca): perf score=1.000000
I20260812 06:18:22.773854 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: MajorDeltaCompactionOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.134s	user 0.102s	sys 0.030s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713264,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":831,"lbm_read_time_us":7504,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27282,"lbm_writes_lt_1ms":443,"mutex_wait_us":235,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12544,"update_count":2000}
I20260812 06:18:22.774502 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca): perf score=10.126437
I20260812 06:18:22.803263 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.028s	user 0.013s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":11557,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:22.803763 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca): perf score=2.188937
I20260812 06:18:22.818236 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.014s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5174,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:22.818959 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling MajorDeltaCompactionOp(415eaa7047df4c18a331111e460c35ca): perf score=1.000000
I20260812 06:18:22.934834 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: MajorDeltaCompactionOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.116s	user 0.083s	sys 0.032s 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":58,"lbm_read_time_us":7273,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21629,"lbm_writes_lt_1ms":443,"mutex_wait_us":28,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10496,"update_count":2000}
I20260812 06:18:22.935425 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca): perf score=10.126437
I20260812 06:18:22.974987 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.039s	user 0.021s	sys 0.015s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":13013,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:22.975519 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca): perf score=2.188937
I20260812 06:18:22.985351 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3690,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:22.985765 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling FlushMRSOp(415eaa7047df4c18a331111e460c35ca): perf score=1.000000
I20260812 06:18:23.016408 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: FlushMRSOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.030s	user 0.026s	sys 0.001s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":61,"dirs.run_cpu_time_us":180,"dirs.run_wall_time_us":1227,"drs_written":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1191,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:23.017093 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling MajorDeltaCompactionOp(415eaa7047df4c18a331111e460c35ca): perf score=1.000000
I20260812 06:18:23.160113 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: MajorDeltaCompactionOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.143s	user 0.093s	sys 0.038s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":170,"lbm_read_time_us":7801,"lbm_reads_lt_1ms":464,"lbm_write_time_us":21982,"lbm_writes_lt_1ms":443,"mutex_wait_us":16,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":19200,"update_count":2000}
I20260812 06:18:23.162847 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling LogGCOp(415eaa7047df4c18a331111e460c35ca): free 124257245 bytes of WAL
I20260812 06:18:23.163105 21522 log_reader.cc:385] T 415eaa7047df4c18a331111e460c35ca: removed 12 log segments from log reader
I20260812 06:18:23.163154 21522 log.cc:1079] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/415eaa7047df4c18a331111e460c35ca/wal-000000015 (ops 71-75)
I20260812 06:18:23.163183 21522 log.cc:1079] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/415eaa7047df4c18a331111e460c35ca/wal-000000016 (ops 76-80)
I20260812 06:18:23.163216 21522 log.cc:1079] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/415eaa7047df4c18a331111e460c35ca/wal-000000017 (ops 81-85)
I20260812 06:18:23.163249 21522 log.cc:1079] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/415eaa7047df4c18a331111e460c35ca/wal-000000018 (ops 86-90)
I20260812 06:18:23.163280 21522 log.cc:1079] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/415eaa7047df4c18a331111e460c35ca/wal-000000019 (ops 91-95)
I20260812 06:18:23.163311 21522 log.cc:1079] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/415eaa7047df4c18a331111e460c35ca/wal-000000020 (ops 96-100)
I20260812 06:18:23.163342 21522 log.cc:1079] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/415eaa7047df4c18a331111e460c35ca/wal-000000021 (ops 101-105)
I20260812 06:18:23.163373 21522 log.cc:1079] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/415eaa7047df4c18a331111e460c35ca/wal-000000022 (ops 106-110)
I20260812 06:18:23.163404 21522 log.cc:1079] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/415eaa7047df4c18a331111e460c35ca/wal-000000023 (ops 111-114)
I20260812 06:18:23.163434 21522 log.cc:1079] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/415eaa7047df4c18a331111e460c35ca/wal-000000024 (ops 115-119)
I20260812 06:18:23.163466 21522 log.cc:1079] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/415eaa7047df4c18a331111e460c35ca/wal-000000025 (ops 120-124)
I20260812 06:18:23.163496 21522 log.cc:1079] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/415eaa7047df4c18a331111e460c35ca/wal-000000026 (ops 125-129)
I20260812 06:18:23.187222 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: LogGCOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.024s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:18:23.187698 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling UndoDeltaBlockGCOp(415eaa7047df4c18a331111e460c35ca): 448 bytes on disk
I20260812 06:18:23.188604 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: UndoDeltaBlockGCOp(415eaa7047df4c18a331111e460c35ca) 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:18:23.189132 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca): perf score=15.087375
I20260812 06:18:23.234334 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.045s	user 0.022s	sys 0.020s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":20981,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":412,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2050}
I20260812 06:18:23.234807 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca): perf score=2.188937
I20260812 06:18:23.245301 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3449,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:23.245729 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca): perf score=2.188937
I20260812 06:18:23.264489 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.019s	user 0.011s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4614,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:23.264978 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling MajorDeltaCompactionOp(415eaa7047df4c18a331111e460c35ca): perf score=1.000000
I20260812 06:18:23.451102 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: MajorDeltaCompactionOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.186s	user 0.143s	sys 0.037s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918201,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":935,"lbm_read_time_us":14247,"lbm_reads_lt_1ms":673,"lbm_write_time_us":30477,"lbm_writes_lt_1ms":643,"mutex_wait_us":278,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":13440,"update_count":3000}
I20260812 06:18:23.451673 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca): perf score=14.095187
I20260812 06:18:23.517069 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.065s	user 0.032s	sys 0.018s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":33041,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:23.517665 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca): perf score=2.188937
I20260812 06:18:23.534525 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.017s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5689,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:23.534968 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling MajorDeltaCompactionOp(415eaa7047df4c18a331111e460c35ca): perf score=1.000000
I20260812 06:18:23.691928 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: MajorDeltaCompactionOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.157s	user 0.108s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1767,"lbm_read_time_us":9506,"lbm_reads_lt_1ms":564,"lbm_write_time_us":25596,"lbm_writes_lt_1ms":543,"mutex_wait_us":895,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10624,"update_count":2500}
I20260812 06:18:23.692461 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca): perf score=14.095187
I20260812 06:18:23.738466 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.046s	user 0.011s	sys 0.032s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21818,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:18:23.739112 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca): perf score=2.188937
I20260812 06:18:23.768600 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.029s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5206,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:23.769131 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca): perf score=2.188937
I20260812 06:18:23.779253 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3790,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:23.779665 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling MajorDeltaCompactionOp(415eaa7047df4c18a331111e460c35ca): perf score=1.000000
I20260812 06:18:23.972030 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: MajorDeltaCompactionOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.192s	user 0.123s	sys 0.068s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918214,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":178,"lbm_read_time_us":12227,"lbm_reads_lt_1ms":673,"lbm_write_time_us":37469,"lbm_writes_lt_1ms":643,"mutex_wait_us":50,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":3000}
I20260812 06:18:23.974515 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca): perf score=14.095187
I20260812 06:18:24.029383 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.055s	user 0.021s	sys 0.032s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":22954,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:24.030009 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca): perf score=2.188937
I20260812 06:18:24.040242 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3859,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:24.040871 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling MajorDeltaCompactionOp(415eaa7047df4c18a331111e460c35ca): perf score=1.000000
I20260812 06:18:24.216373 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: MajorDeltaCompactionOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.175s	user 0.108s	sys 0.060s 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":215,"lbm_read_time_us":14113,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28293,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2500}
I20260812 06:18:24.216950 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca): perf score=14.095187
I20260812 06:18:24.282693 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.066s	user 0.028s	sys 0.027s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22210,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:24.283269 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca): perf score=2.188937
I20260812 06:18:24.293151 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3641,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:24.293643 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling MajorDeltaCompactionOp(415eaa7047df4c18a331111e460c35ca): perf score=1.000000
I20260812 06:18:24.463857 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: MajorDeltaCompactionOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.170s	user 0.115s	sys 0.055s 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":219,"lbm_read_time_us":12448,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30239,"lbm_writes_lt_1ms":543,"mutex_wait_us":49,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13952,"update_count":2500}
I20260812 06:18:24.464485 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca): perf score=10.126437
I20260812 06:18:24.496723 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.032s	user 0.019s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14291,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:24.497184 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca): perf score=2.188937
I20260812 06:18:24.510771 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.013s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5294,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:24.511281 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling FlushMRSOp(415eaa7047df4c18a331111e460c35ca): perf score=1.000000
I20260812 06:18:24.537263 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: FlushMRSOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.026s	user 0.020s	sys 0.004s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":55,"dirs.run_cpu_time_us":179,"dirs.run_wall_time_us":1125,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1600,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:24.537900 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling LogGCOp(415eaa7047df4c18a331111e460c35ca): free 124710562 bytes of WAL
I20260812 06:18:24.538143 21522 log_reader.cc:385] T 415eaa7047df4c18a331111e460c35ca: removed 12 log segments from log reader
I20260812 06:18:24.538262 21522 log.cc:1079] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/415eaa7047df4c18a331111e460c35ca/wal-000000027 (ops 130-134)
I20260812 06:18:24.538344 21522 log.cc:1079] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/415eaa7047df4c18a331111e460c35ca/wal-000000028 (ops 135-139)
I20260812 06:18:24.538403 21522 log.cc:1079] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/415eaa7047df4c18a331111e460c35ca/wal-000000029 (ops 140-144)
I20260812 06:18:24.538453 21522 log.cc:1079] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/415eaa7047df4c18a331111e460c35ca/wal-000000030 (ops 145-149)
I20260812 06:18:24.538506 21522 log.cc:1079] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/415eaa7047df4c18a331111e460c35ca/wal-000000031 (ops 150-154)
I20260812 06:18:24.538554 21522 log.cc:1079] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/415eaa7047df4c18a331111e460c35ca/wal-000000032 (ops 155-159)
I20260812 06:18:24.538612 21522 log.cc:1079] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/415eaa7047df4c18a331111e460c35ca/wal-000000033 (ops 160-164)
I20260812 06:18:24.538663 21522 log.cc:1079] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/415eaa7047df4c18a331111e460c35ca/wal-000000034 (ops 165-169)
I20260812 06:18:24.538712 21522 log.cc:1079] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/415eaa7047df4c18a331111e460c35ca/wal-000000035 (ops 170-174)
I20260812 06:18:24.538762 21522 log.cc:1079] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/415eaa7047df4c18a331111e460c35ca/wal-000000036 (ops 175-179)
I20260812 06:18:24.538811 21522 log.cc:1079] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/415eaa7047df4c18a331111e460c35ca/wal-000000037 (ops 180-184)
I20260812 06:18:24.538863 21522 log.cc:1079] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/415eaa7047df4c18a331111e460c35ca/wal-000000038 (ops 185-189)
I20260812 06:18:24.560799 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: LogGCOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.023s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:18:24.561324 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling UndoDeltaBlockGCOp(415eaa7047df4c18a331111e460c35ca): 492 bytes on disk
I20260812 06:18:24.561825 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: UndoDeltaBlockGCOp(415eaa7047df4c18a331111e460c35ca) 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:18:24.562357 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca): perf score=6.157687
I20260812 06:18:24.584233 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.022s	user 0.011s	sys 0.010s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":9234,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:18:24.584920 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling MajorDeltaCompactionOp(415eaa7047df4c18a331111e460c35ca): perf score=1.000000
I20260812 06:18:24.763549 21365 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.591s	user 1.680s	sys 0.153s
I20260812 06:18:24.768937 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: MajorDeltaCompactionOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.184s	user 0.144s	sys 0.040s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918216,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":311,"lbm_read_time_us":13258,"lbm_reads_lt_1ms":669,"lbm_write_time_us":31098,"lbm_writes_lt_1ms":643,"mutex_wait_us":19,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":10880,"thread_start_us":69,"threads_started":1,"update_count":3000}
I20260812 06:18:24.769424 21618 maintenance_manager.cc:419] P 8d765999e3ad4b97b48d0948b2fb171a: Scheduling FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca): perf score=14.095187
I20260812 06:18:24.798161 21365 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.034s	user 0.003s	sys 0.000s
I20260812 06:18:24.798918 21365 tablet_server.cc:179] TabletServer@127.20.221.65:0 shutting down...
I20260812 06:18:24.811095 21522 maintenance_manager.cc:643] P 8d765999e3ad4b97b48d0948b2fb171a: FlushDeltaMemStoresOp(415eaa7047df4c18a331111e460c35ca) complete. Timing: real 0.041s	user 0.031s	sys 0.007s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19284,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:24.811664 21365 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:24.812069 21365 tablet_replica.cc:333] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a: stopping tablet replica
I20260812 06:18:24.812264 21365 raft_consensus.cc:2243] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:24.820555 21365 raft_consensus.cc:2272] T 415eaa7047df4c18a331111e460c35ca P 8d765999e3ad4b97b48d0948b2fb171a [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:24.835222 21365 tablet_server.cc:196] TabletServer@127.20.221.65:0 shutdown complete.
I20260812 06:18:24.839696 21365 master.cc:562] Master@127.20.221.126:42403 shutting down...
I20260812 06:18:24.842701 21365 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 760be29ac4464673b39bea1d3c6f4c6f [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:24.842865 21365 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 760be29ac4464673b39bea1d3c6f4c6f [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:24.842936 21365 tablet_replica.cc:333] T 00000000000000000000000000000000 P 760be29ac4464673b39bea1d3c6f4c6f: stopping tablet replica
I20260812 06:18:24.854998 21365 master.cc:584] Master@127.20.221.126:42403 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5013 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:24.926455 21365 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.20.221.126:42657
I20260812 06:18:24.926788 21365 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:24.928604 21664 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:18:24.928769 21661 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:18:24.928813 21365 server_base.cc:1061] running on GCE node
W20260812 06:18:24.928612 21668 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:18:24.929024 21365 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:24.929064 21365 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:18:24.929085 21365 hybrid_clock.cc:648] HybridClock initialized: now 1786515504929084 us; error 0 us; skew 500 ppm
I20260812 06:18:24.929824 21365 webserver.cc:533] Webserver started at http://127.20.221.126:41177/ using document root <none> and password file <none>
I20260812 06:18:24.929975 21365 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:24.930023 21365 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:24.930105 21365 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:24.930461 21365 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515499903233-21365-0/minicluster-data/master-0-root/instance:
uuid: "e49bb6b263ac4c6daabdf68538316459"
format_stamp: "Formatted at 2026-08-12 06:18:24 on dist-test-slave-jlzn"
I20260812 06:18:24.931876 21365 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:24.932720 21676 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:18:24.932916 21365 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:24.932986 21365 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515499903233-21365-0/minicluster-data/master-0-root
uuid: "e49bb6b263ac4c6daabdf68538316459"
format_stamp: "Formatted at 2026-08-12 06:18:24 on dist-test-slave-jlzn"
I20260812 06:18:24.933053 21365 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515499903233-21365-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515499903233-21365-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515499903233-21365-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:18:24.951865 21365 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:24.952275 21365 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:24.956147 21365 rpc_server.cc:307] RPC server started. Bound to: 127.20.221.126:42657
I20260812 06:18:24.961565 21756 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.20.221.126:42657 every 8 connection(s)
I20260812 06:18:24.962003 21758 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:18:24.963711 21758 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P e49bb6b263ac4c6daabdf68538316459: Bootstrap starting.
I20260812 06:18:24.964483 21758 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P e49bb6b263ac4c6daabdf68538316459: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:24.965396 21758 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P e49bb6b263ac4c6daabdf68538316459: No bootstrap required, opened a new log
I20260812 06:18:24.965775 21758 raft_consensus.cc:359] T 00000000000000000000000000000000 P e49bb6b263ac4c6daabdf68538316459 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e49bb6b263ac4c6daabdf68538316459" member_type: VOTER }
I20260812 06:18:24.965862 21758 raft_consensus.cc:385] T 00000000000000000000000000000000 P e49bb6b263ac4c6daabdf68538316459 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:24.965893 21758 raft_consensus.cc:740] T 00000000000000000000000000000000 P e49bb6b263ac4c6daabdf68538316459 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: e49bb6b263ac4c6daabdf68538316459, State: Initialized, Role: FOLLOWER
I20260812 06:18:24.966028 21758 consensus_queue.cc:260] T 00000000000000000000000000000000 P e49bb6b263ac4c6daabdf68538316459 [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: "e49bb6b263ac4c6daabdf68538316459" member_type: VOTER }
I20260812 06:18:24.966104 21758 raft_consensus.cc:399] T 00000000000000000000000000000000 P e49bb6b263ac4c6daabdf68538316459 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:24.966145 21758 raft_consensus.cc:493] T 00000000000000000000000000000000 P e49bb6b263ac4c6daabdf68538316459 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:24.966193 21758 raft_consensus.cc:3060] T 00000000000000000000000000000000 P e49bb6b263ac4c6daabdf68538316459 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:24.966832 21758 raft_consensus.cc:515] T 00000000000000000000000000000000 P e49bb6b263ac4c6daabdf68538316459 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e49bb6b263ac4c6daabdf68538316459" member_type: VOTER }
I20260812 06:18:24.966952 21758 leader_election.cc:304] T 00000000000000000000000000000000 P e49bb6b263ac4c6daabdf68538316459 [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: e49bb6b263ac4c6daabdf68538316459; no voters: 
I20260812 06:18:24.967129 21758 leader_election.cc:290] T 00000000000000000000000000000000 P e49bb6b263ac4c6daabdf68538316459 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:24.967226 21765 raft_consensus.cc:2804] T 00000000000000000000000000000000 P e49bb6b263ac4c6daabdf68538316459 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:24.967418 21765 raft_consensus.cc:697] T 00000000000000000000000000000000 P e49bb6b263ac4c6daabdf68538316459 [term 1 LEADER]: Becoming Leader. State: Replica: e49bb6b263ac4c6daabdf68538316459, State: Running, Role: LEADER
I20260812 06:18:24.967535 21758 sys_catalog.cc:565] T 00000000000000000000000000000000 P e49bb6b263ac4c6daabdf68538316459 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:24.967578 21765 consensus_queue.cc:237] T 00000000000000000000000000000000 P e49bb6b263ac4c6daabdf68538316459 [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: "e49bb6b263ac4c6daabdf68538316459" member_type: VOTER }
I20260812 06:18:24.968047 21767 sys_catalog.cc:455] T 00000000000000000000000000000000 P e49bb6b263ac4c6daabdf68538316459 [sys.catalog]: SysCatalogTable state changed. Reason: New leader e49bb6b263ac4c6daabdf68538316459. Latest consensus state: current_term: 1 leader_uuid: "e49bb6b263ac4c6daabdf68538316459" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e49bb6b263ac4c6daabdf68538316459" member_type: VOTER } }
I20260812 06:18:24.968025 21766 sys_catalog.cc:455] T 00000000000000000000000000000000 P e49bb6b263ac4c6daabdf68538316459 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "e49bb6b263ac4c6daabdf68538316459" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e49bb6b263ac4c6daabdf68538316459" member_type: VOTER } }
I20260812 06:18:24.968149 21767 sys_catalog.cc:458] T 00000000000000000000000000000000 P e49bb6b263ac4c6daabdf68538316459 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:24.968164 21766 sys_catalog.cc:458] T 00000000000000000000000000000000 P e49bb6b263ac4c6daabdf68538316459 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:24.968402 21772 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:24.969317 21772 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:24.969507 21365 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:24.971019 21772 catalog_manager.cc:1383] Generated new cluster ID: b740ed0f7c7b40f994c0698787e57510
I20260812 06:18:24.971066 21772 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:24.980410 21772 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:24.980916 21772 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:25.000003 21772 catalog_manager.cc:6092] T 00000000000000000000000000000000 P e49bb6b263ac4c6daabdf68538316459: Generated new TSK 0
I20260812 06:18:25.000196 21772 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:25.001649 21365 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:25.003459 21790 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:18:25.003487 21795 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:18:25.003532 21365 server_base.cc:1061] running on GCE node
W20260812 06:18:25.003463 21793 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:18:25.003906 21365 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:25.003957 21365 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:18:25.003976 21365 hybrid_clock.cc:648] HybridClock initialized: now 1786515505003976 us; error 0 us; skew 500 ppm
I20260812 06:18:25.004735 21365 webserver.cc:533] Webserver started at http://127.20.221.65:34521/ using document root <none> and password file <none>
I20260812 06:18:25.004879 21365 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:25.004935 21365 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:25.005008 21365 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:25.005364 21365 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515499903233-21365-0/minicluster-data/ts-0-root/instance:
uuid: "57424ec84e9a44ff9fb7dbc56ed334ca"
format_stamp: "Formatted at 2026-08-12 06:18:25 on dist-test-slave-jlzn"
I20260812 06:18:25.006722 21365 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:25.007514 21800 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:18:25.007700 21365 fs_manager.cc:730] Time spent opening block manager: real 0.000s	user 0.001s	sys 0.000s
I20260812 06:18:25.007766 21365 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515499903233-21365-0/minicluster-data/ts-0-root
uuid: "57424ec84e9a44ff9fb7dbc56ed334ca"
format_stamp: "Formatted at 2026-08-12 06:18:25 on dist-test-slave-jlzn"
I20260812 06:18:25.007854 21365 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515499903233-21365-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515499903233-21365-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515499903233-21365-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:18:25.015978 21365 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:25.016273 21365 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:25.016521 21365 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:25.016922 21365 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:25.016959 21365 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:25.016999 21365 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:25.017026 21365 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:25.020867 21365 rpc_server.cc:307] RPC server started. Bound to: 127.20.221.65:34079
I20260812 06:18:25.021145 21918 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.20.221.65:34079 every 8 connection(s)
I20260812 06:18:25.025285 21919 heartbeater.cc:344] Connected to a master server at 127.20.221.126:42657
I20260812 06:18:25.025365 21919 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:25.025525 21919 heartbeater.cc:507] Master 127.20.221.126:42657 requested a full tablet report, sending...
I20260812 06:18:25.026075 21699 ts_manager.cc:194] Registered new tserver with Master: 57424ec84e9a44ff9fb7dbc56ed334ca (127.20.221.65:34079)
I20260812 06:18:25.026712 21699 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:60926
I20260812 06:18:25.026837 21365 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.00550076s
I20260812 06:18:25.032801 21699 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:60942:
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:18:25.040395 21855 tablet_service.cc:1511] Processing CreateTablet for tablet 9c10c7f2454b4d91a90fe95d2af6b874 (DEFAULT_TABLE table=heavy-update-compaction-test [id=3b729d265f3d4ab782d830c021071ebf]), partition=
I20260812 06:18:25.040637 21855 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 9c10c7f2454b4d91a90fe95d2af6b874. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:25.042347 21936 tablet_bootstrap.cc:492] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca: Bootstrap starting.
I20260812 06:18:25.043291 21936 tablet_bootstrap.cc:654] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:25.044185 21936 tablet_bootstrap.cc:492] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca: No bootstrap required, opened a new log
I20260812 06:18:25.044253 21936 ts_tablet_manager.cc:1403] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:18:25.044595 21936 raft_consensus.cc:359] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "57424ec84e9a44ff9fb7dbc56ed334ca" member_type: VOTER last_known_addr { host: "127.20.221.65" port: 34079 } }
I20260812 06:18:25.044674 21936 raft_consensus.cc:385] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:25.044700 21936 raft_consensus.cc:740] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 57424ec84e9a44ff9fb7dbc56ed334ca, State: Initialized, Role: FOLLOWER
I20260812 06:18:25.044790 21936 consensus_queue.cc:260] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca [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: "57424ec84e9a44ff9fb7dbc56ed334ca" member_type: VOTER last_known_addr { host: "127.20.221.65" port: 34079 } }
I20260812 06:18:25.044847 21936 raft_consensus.cc:399] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:25.044870 21936 raft_consensus.cc:493] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:25.044901 21936 raft_consensus.cc:3060] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:25.045558 21936 raft_consensus.cc:515] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "57424ec84e9a44ff9fb7dbc56ed334ca" member_type: VOTER last_known_addr { host: "127.20.221.65" port: 34079 } }
I20260812 06:18:25.045701 21936 leader_election.cc:304] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca [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: 57424ec84e9a44ff9fb7dbc56ed334ca; no voters: 
I20260812 06:18:25.045888 21936 leader_election.cc:290] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:25.045996 21941 raft_consensus.cc:2804] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:25.046201 21919 heartbeater.cc:499] Master 127.20.221.126:42657 was elected leader, sending a full tablet report...
I20260812 06:18:25.046236 21941 raft_consensus.cc:697] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca [term 1 LEADER]: Becoming Leader. State: Replica: 57424ec84e9a44ff9fb7dbc56ed334ca, State: Running, Role: LEADER
I20260812 06:18:25.046190 21936 ts_tablet_manager.cc:1434] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:25.046413 21941 consensus_queue.cc:237] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca [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: "57424ec84e9a44ff9fb7dbc56ed334ca" member_type: VOTER last_known_addr { host: "127.20.221.65" port: 34079 } }
I20260812 06:18:25.047590 21699 catalog_manager.cc:5719] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca reported cstate change: term changed from 0 to 1, leader changed from <none> to 57424ec84e9a44ff9fb7dbc56ed334ca (127.20.221.65). New cstate: current_term: 1 leader_uuid: "57424ec84e9a44ff9fb7dbc56ed334ca" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "57424ec84e9a44ff9fb7dbc56ed334ca" member_type: VOTER last_known_addr { host: "127.20.221.65" port: 34079 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:25.098313 21365 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.047s	user 0.010s	sys 0.011s
I20260812 06:18:25.271968 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling FlushMRSOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=23.023690
I20260812 06:18:25.426726 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: FlushMRSOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.155s	user 0.114s	sys 0.035s Metrics: {"bytes_written":15999660,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":42,"dirs.run_cpu_time_us":196,"dirs.run_wall_time_us":827,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":41635,"lbm_writes_lt_1ms":957,"peak_mem_usage":0,"reinsert_count":0,"rows_written":106,"update_count":1950}
I20260812 06:18:25.427367 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling LogGCOp(9c10c7f2454b4d91a90fe95d2af6b874): free 32761802 bytes of WAL
I20260812 06:18:25.427618 21810 log_reader.cc:385] T 9c10c7f2454b4d91a90fe95d2af6b874: removed 3 log segments from log reader
I20260812 06:18:25.427668 21810 log.cc:1079] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/9c10c7f2454b4d91a90fe95d2af6b874/wal-000000001 (ops 1-6)
I20260812 06:18:25.427698 21810 log.cc:1079] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/9c10c7f2454b4d91a90fe95d2af6b874/wal-000000002 (ops 7-11)
I20260812 06:18:25.427714 21810 log.cc:1079] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/9c10c7f2454b4d91a90fe95d2af6b874/wal-000000003 (ops 12-16)
I20260812 06:18:25.432911 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: LogGCOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.005s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:18:25.433233 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=2.188937
I20260812 06:18:25.444541 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.011s	user 0.004s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4262,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:25.444963 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling UndoDeltaBlockGCOp(9c10c7f2454b4d91a90fe95d2af6b874): 20924070 bytes on disk
I20260812 06:18:25.445412 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: UndoDeltaBlockGCOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4}
I20260812 06:18:25.445784 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling MajorDeltaCompactionOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=1.000000
I20260812 06:18:25.608471 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: MajorDeltaCompactionOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.163s	user 0.110s	sys 0.043s Metrics: {"cfile_cache_miss":522,"cfile_cache_miss_bytes":24446412,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":522,"lbm_read_time_us":10771,"lbm_reads_lt_1ms":550,"lbm_write_time_us":25594,"lbm_writes_lt_1ms":533,"peak_mem_usage":61665166,"reinsert_count":0,"thread_start_us":284,"threads_started":5,"update_count":2450}
I20260812 06:18:25.609110 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=14.095187
I20260812 06:18:25.650175 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.041s	user 0.016s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17153,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:25.650677 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling MajorDeltaCompactionOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=1.000000
I20260812 06:18:25.796394 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: MajorDeltaCompactionOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.146s	user 0.090s	sys 0.048s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20754122,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":196,"lbm_read_time_us":10572,"lbm_reads_lt_1ms":463,"lbm_write_time_us":22357,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2000}
I20260812 06:18:25.796993 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=14.095187
I20260812 06:18:25.839495 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.042s	user 0.022s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":15804,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:25.839986 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=2.188937
I20260812 06:18:25.849637 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3666,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:25.850208 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling MajorDeltaCompactionOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=1.000000
I20260812 06:18:26.026048 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: MajorDeltaCompactionOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.176s	user 0.119s	sys 0.043s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24856653,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":879,"lbm_read_time_us":10900,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26181,"lbm_writes_lt_1ms":543,"mutex_wait_us":235,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3712,"update_count":2500}
I20260812 06:18:26.026535 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=14.095187
I20260812 06:18:26.073261 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.047s	user 0.033s	sys 0.003s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":15871,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:26.073730 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=2.188937
I20260812 06:18:26.083652 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3690,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:26.084172 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling MajorDeltaCompactionOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=1.000000
I20260812 06:18:26.238664 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: MajorDeltaCompactionOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.154s	user 0.127s	sys 0.021s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24856652,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":835,"lbm_read_time_us":11388,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26699,"lbm_writes_lt_1ms":543,"mutex_wait_us":52,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13952,"update_count":2500}
I20260812 06:18:26.239881 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=10.126437
I20260812 06:18:26.275694 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.036s	user 0.024s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15466,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:26.276472 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=2.188937
I20260812 06:18:26.292038 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.015s	user 0.012s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5144,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":9088,"update_count":500}
I20260812 06:18:26.292557 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling MajorDeltaCompactionOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=1.000000
I20260812 06:18:26.439502 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: MajorDeltaCompactionOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.147s	user 0.116s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20754242,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":292,"lbm_read_time_us":10210,"lbm_reads_lt_1ms":468,"lbm_write_time_us":25962,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:18:26.440141 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=11.118625
I20260812 06:18:26.476789 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.036s	user 0.012s	sys 0.023s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":16055,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:26.477250 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=2.188937
I20260812 06:18:26.499399 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.022s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3521,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:26.499914 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=2.188937
I20260812 06:18:26.512559 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.012s	user 0.011s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4498,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:26.513080 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling MajorDeltaCompactionOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=1.000000
I20260812 06:18:26.664934 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: MajorDeltaCompactionOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.152s	user 0.119s	sys 0.031s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24856765,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":200,"lbm_read_time_us":12962,"lbm_reads_lt_1ms":573,"lbm_write_time_us":26217,"lbm_writes_lt_1ms":543,"mutex_wait_us":43,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":17664,"update_count":2500}
I20260812 06:18:26.665529 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=10.126437
I20260812 06:18:26.701265 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.036s	user 0.023s	sys 0.008s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":13522,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:26.701810 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling FlushMRSOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=1.000000
I20260812 06:18:26.738677 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: FlushMRSOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.037s	user 0.020s	sys 0.004s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":44,"dirs.run_cpu_time_us":208,"dirs.run_wall_time_us":1229,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1488,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:18:26.739423 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=3.181125
I20260812 06:18:26.753177 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.014s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":3725,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:26.753695 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling LogGCOp(9c10c7f2454b4d91a90fe95d2af6b874): free 117302566 bytes of WAL
I20260812 06:18:26.753908 21810 log_reader.cc:385] T 9c10c7f2454b4d91a90fe95d2af6b874: removed 12 log segments from log reader
I20260812 06:18:26.753957 21810 log.cc:1079] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/9c10c7f2454b4d91a90fe95d2af6b874/wal-000000004 (ops 17-21)
I20260812 06:18:26.753994 21810 log.cc:1079] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/9c10c7f2454b4d91a90fe95d2af6b874/wal-000000005 (ops 22-26)
I20260812 06:18:26.754026 21810 log.cc:1079] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/9c10c7f2454b4d91a90fe95d2af6b874/wal-000000006 (ops 27-30)
I20260812 06:18:26.754058 21810 log.cc:1079] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/9c10c7f2454b4d91a90fe95d2af6b874/wal-000000007 (ops 31-35)
I20260812 06:18:26.754104 21810 log.cc:1079] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/9c10c7f2454b4d91a90fe95d2af6b874/wal-000000008 (ops 36-40)
I20260812 06:18:26.754136 21810 log.cc:1079] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/9c10c7f2454b4d91a90fe95d2af6b874/wal-000000009 (ops 41-44)
I20260812 06:18:26.754168 21810 log.cc:1079] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/9c10c7f2454b4d91a90fe95d2af6b874/wal-000000010 (ops 45-49)
I20260812 06:18:26.754196 21810 log.cc:1079] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/9c10c7f2454b4d91a90fe95d2af6b874/wal-000000011 (ops 50-54)
I20260812 06:18:26.754227 21810 log.cc:1079] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/9c10c7f2454b4d91a90fe95d2af6b874/wal-000000012 (ops 55-59)
I20260812 06:18:26.754256 21810 log.cc:1079] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/9c10c7f2454b4d91a90fe95d2af6b874/wal-000000013 (ops 60-64)
I20260812 06:18:26.754287 21810 log.cc:1079] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/9c10c7f2454b4d91a90fe95d2af6b874/wal-000000014 (ops 65-69)
I20260812 06:18:26.754316 21810 log.cc:1079] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/9c10c7f2454b4d91a90fe95d2af6b874/wal-000000015 (ops 70-74)
I20260812 06:18:26.774039 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: LogGCOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.020s	user 0.000s	sys 0.018s Metrics: {}
I20260812 06:18:26.774504 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling UndoDeltaBlockGCOp(9c10c7f2454b4d91a90fe95d2af6b874): 482 bytes on disk
I20260812 06:18:26.774893 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: UndoDeltaBlockGCOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4}
I20260812 06:18:26.775420 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=2.188937
I20260812 06:18:26.795279 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.020s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5477,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:26.795748 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling LogGCOp(9c10c7f2454b4d91a90fe95d2af6b874): free 11564875 bytes of WAL
I20260812 06:18:26.796023 21810 log_reader.cc:385] T 9c10c7f2454b4d91a90fe95d2af6b874: removed 1 log segments from log reader
I20260812 06:18:26.796079 21810 log.cc:1079] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/9c10c7f2454b4d91a90fe95d2af6b874/wal-000000016 (ops 75-78)
I20260812 06:18:26.798472 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: LogGCOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:18:26.798738 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=2.188937
I20260812 06:18:26.811872 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.013s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4630,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:26.812347 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling MajorDeltaCompactionOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=1.000000
I20260812 06:18:26.989104 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: MajorDeltaCompactionOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.177s	user 0.112s	sys 0.064s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28959293,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":183,"lbm_read_time_us":12164,"lbm_reads_lt_1ms":674,"lbm_write_time_us":30031,"lbm_writes_lt_1ms":643,"mutex_wait_us":52,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":9472,"thread_start_us":71,"threads_started":1,"update_count":3000}
I20260812 06:18:26.989625 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=14.095187
I20260812 06:18:27.037076 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.047s	user 0.027s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20032,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:27.037611 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=3.181125
I20260812 06:18:27.061415 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.024s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":6252,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:27.061895 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=2.188937
I20260812 06:18:27.070673 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.009s	user 0.000s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3145,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:27.071070 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling MajorDeltaCompactionOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=1.000000
I20260812 06:18:27.219602 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: MajorDeltaCompactionOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.148s	user 0.108s	sys 0.040s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28959173,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":128,"lbm_read_time_us":10820,"lbm_reads_lt_1ms":673,"lbm_write_time_us":30800,"lbm_writes_lt_1ms":643,"mutex_wait_us":33,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6528,"update_count":3000}
I20260812 06:18:27.220108 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=14.095187
I20260812 06:18:27.263706 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.043s	user 0.028s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19206,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:27.264305 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=2.188937
I20260812 06:18:27.279918 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.015s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5985,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:27.280320 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling MajorDeltaCompactionOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=1.000000
I20260812 06:18:27.429142 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: MajorDeltaCompactionOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.149s	user 0.103s	sys 0.032s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24856653,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":879,"lbm_read_time_us":11047,"lbm_reads_lt_1ms":568,"lbm_write_time_us":25672,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2500}
I20260812 06:18:27.429745 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=14.095187
I20260812 06:18:27.484228 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.054s	user 0.028s	sys 0.009s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":16647,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:27.484772 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=2.188937
I20260812 06:18:27.494521 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3488,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:27.495203 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling MajorDeltaCompactionOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=1.000000
I20260812 06:18:27.661850 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: MajorDeltaCompactionOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.166s	user 0.126s	sys 0.039s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24856652,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":271,"lbm_read_time_us":12317,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25774,"lbm_writes_lt_1ms":543,"mutex_wait_us":40,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":21376,"update_count":2500}
I20260812 06:18:27.662431 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=14.095187
I20260812 06:18:27.709249 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.047s	user 0.024s	sys 0.019s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20281,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:27.709748 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling MajorDeltaCompactionOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=1.000000
I20260812 06:18:27.865451 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: MajorDeltaCompactionOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.156s	user 0.089s	sys 0.052s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20754123,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":294,"lbm_read_time_us":10036,"lbm_reads_lt_1ms":463,"lbm_write_time_us":21693,"lbm_writes_lt_1ms":443,"mutex_wait_us":2,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2000}
I20260812 06:18:27.866039 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=14.095187
I20260812 06:18:27.919206 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.053s	user 0.033s	sys 0.012s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":21357,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:27.920311 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=2.188937
I20260812 06:18:27.937091 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.017s	user 0.009s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6217,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:27.937546 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling MajorDeltaCompactionOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=1.000000
I20260812 06:18:28.095963 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: MajorDeltaCompactionOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.158s	user 0.108s	sys 0.043s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24856652,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":264,"lbm_read_time_us":9841,"lbm_reads_lt_1ms":572,"lbm_write_time_us":23236,"lbm_writes_lt_1ms":543,"mutex_wait_us":38,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:18:28.096542 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=14.095187
I20260812 06:18:28.145192 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.048s	user 0.033s	sys 0.014s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":22121,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:28.145778 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=2.188937
I20260812 06:18:28.166142 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.020s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4886,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:28.166694 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling FlushMRSOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=1.000000
I20260812 06:18:28.229650 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: FlushMRSOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.063s	user 0.038s	sys 0.000s Metrics: {"bytes_written":1357579,"cfile_init":1,"dirs.queue_time_us":48,"dirs.run_cpu_time_us":162,"dirs.run_wall_time_us":1240,"drs_written":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2380,"lbm_writes_lt_1ms":44,"peak_mem_usage":0,"rows_written":33}
I20260812 06:18:28.230374 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling LogGCOp(9c10c7f2454b4d91a90fe95d2af6b874): free 124710342 bytes of WAL
I20260812 06:18:28.230631 21810 log_reader.cc:385] T 9c10c7f2454b4d91a90fe95d2af6b874: removed 12 log segments from log reader
I20260812 06:18:28.230684 21810 log.cc:1079] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/9c10c7f2454b4d91a90fe95d2af6b874/wal-000000017 (ops 79-83)
I20260812 06:18:28.230721 21810 log.cc:1079] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/9c10c7f2454b4d91a90fe95d2af6b874/wal-000000018 (ops 84-88)
I20260812 06:18:28.230754 21810 log.cc:1079] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/9c10c7f2454b4d91a90fe95d2af6b874/wal-000000019 (ops 89-93)
I20260812 06:18:28.230785 21810 log.cc:1079] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/9c10c7f2454b4d91a90fe95d2af6b874/wal-000000020 (ops 94-98)
I20260812 06:18:28.230816 21810 log.cc:1079] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/9c10c7f2454b4d91a90fe95d2af6b874/wal-000000021 (ops 99-103)
I20260812 06:18:28.230846 21810 log.cc:1079] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/9c10c7f2454b4d91a90fe95d2af6b874/wal-000000022 (ops 104-108)
I20260812 06:18:28.230877 21810 log.cc:1079] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/9c10c7f2454b4d91a90fe95d2af6b874/wal-000000023 (ops 109-113)
I20260812 06:18:28.230906 21810 log.cc:1079] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/9c10c7f2454b4d91a90fe95d2af6b874/wal-000000024 (ops 114-118)
I20260812 06:18:28.230937 21810 log.cc:1079] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/9c10c7f2454b4d91a90fe95d2af6b874/wal-000000025 (ops 119-123)
I20260812 06:18:28.230966 21810 log.cc:1079] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/9c10c7f2454b4d91a90fe95d2af6b874/wal-000000026 (ops 124-128)
I20260812 06:18:28.230995 21810 log.cc:1079] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/9c10c7f2454b4d91a90fe95d2af6b874/wal-000000027 (ops 129-133)
I20260812 06:18:28.231024 21810 log.cc:1079] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/9c10c7f2454b4d91a90fe95d2af6b874/wal-000000028 (ops 134-138)
I20260812 06:18:28.250953 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: LogGCOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.020s	user 0.000s	sys 0.017s Metrics: {}
I20260812 06:18:28.251387 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=6.157687
I20260812 06:18:28.279716 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.028s	user 0.019s	sys 0.004s Metrics: {"bytes_written":8205079,"delete_count":0,"lbm_write_time_us":10657,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:18:28.280148 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling LogGCOp(9c10c7f2454b4d91a90fe95d2af6b874): free 8767088 bytes of WAL
I20260812 06:18:28.280331 21810 log_reader.cc:385] T 9c10c7f2454b4d91a90fe95d2af6b874: removed 1 log segments from log reader
I20260812 06:18:28.280376 21810 log.cc:1079] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/9c10c7f2454b4d91a90fe95d2af6b874/wal-000000029 (ops 139-143)
I20260812 06:18:28.281809 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: LogGCOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:18:28.282083 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=2.188937
I20260812 06:18:28.292115 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3497,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:28.292506 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling MajorDeltaCompactionOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=1.000000
I20260812 06:18:28.524093 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: MajorDeltaCompactionOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.231s	user 0.147s	sys 0.080s Metrics: {"cfile_cache_miss":834,"cfile_cache_miss_bytes":37164128,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":4192,"lbm_read_time_us":17792,"lbm_reads_lt_1ms":874,"lbm_write_time_us":39228,"lbm_writes_lt_1ms":843,"mutex_wait_us":3383,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":42112,"thread_start_us":87,"threads_started":1,"update_count":4000}
I20260812 06:18:28.524718 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling UndoDeltaBlockGCOp(9c10c7f2454b4d91a90fe95d2af6b874): 507 bytes on disk
I20260812 06:18:28.525384 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: UndoDeltaBlockGCOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4}
I20260812 06:18:28.526021 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=18.063937
I20260812 06:18:28.572451 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.046s	user 0.034s	sys 0.012s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":18980,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:28.573194 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=2.188937
I20260812 06:18:28.594830 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.021s	user 0.004s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5368,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:28.595260 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=2.188937
I20260812 06:18:28.605013 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3635,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:28.605439 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling MajorDeltaCompactionOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=1.000000
I20260812 06:18:28.788445 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: MajorDeltaCompactionOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.183s	user 0.139s	sys 0.043s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":33061597,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":74,"lbm_read_time_us":13348,"lbm_reads_lt_1ms":773,"lbm_write_time_us":36520,"lbm_writes_lt_1ms":743,"mutex_wait_us":23,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":8576,"update_count":3500}
I20260812 06:18:28.789647 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=14.095187
I20260812 06:18:28.841984 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.051s	user 0.028s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20694,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:28.842515 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=3.181125
I20260812 06:18:28.865233 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.023s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4480,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:28.865828 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=2.188937
I20260812 06:18:28.875747 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.010s	user 0.007s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3586,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:28.876173 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling MajorDeltaCompactionOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=1.000000
I20260812 06:18:29.038635 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: MajorDeltaCompactionOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.162s	user 0.120s	sys 0.040s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28959174,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1146,"lbm_read_time_us":11463,"lbm_reads_lt_1ms":673,"lbm_write_time_us":35359,"lbm_writes_lt_1ms":643,"mutex_wait_us":359,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":3000}
I20260812 06:18:29.039232 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=14.095187
I20260812 06:18:29.086803 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.047s	user 0.023s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20114,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:29.087378 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=2.188937
I20260812 06:18:29.097143 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3638,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:29.097678 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling MajorDeltaCompactionOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=1.000000
I20260812 06:18:29.248389 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: MajorDeltaCompactionOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.150s	user 0.112s	sys 0.027s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24856653,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":204,"lbm_read_time_us":10137,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26192,"lbm_writes_lt_1ms":543,"mutex_wait_us":51,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12160,"update_count":2500}
I20260812 06:18:29.248983 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=14.095187
I20260812 06:18:29.287437 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.038s	user 0.019s	sys 0.016s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":17151,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:29.289530 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling MajorDeltaCompactionOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=1.000000
I20260812 06:18:29.427772 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: MajorDeltaCompactionOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.138s	user 0.092s	sys 0.044s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20754125,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":123,"lbm_read_time_us":8708,"lbm_reads_lt_1ms":467,"lbm_write_time_us":23465,"lbm_writes_lt_1ms":443,"mutex_wait_us":68,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2000}
I20260812 06:18:29.428517 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=11.118625
I20260812 06:18:29.473759 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.044s	user 0.022s	sys 0.018s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17301,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:18:29.474279 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=2.188937
I20260812 06:18:29.485324 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3632,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:29.485967 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=2.188937
I20260812 06:18:29.495182 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.009s	user 0.007s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3290,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:29.495695 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling FlushMRSOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=1.000000
I20260812 06:18:29.533782 21365 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.435s	user 1.646s	sys 0.121s
I20260812 06:18:29.535645 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: FlushMRSOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.040s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1193507,"cfile_init":1,"dirs.queue_time_us":47,"dirs.run_cpu_time_us":207,"dirs.run_wall_time_us":1254,"drs_written":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1808,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:18:29.536350 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling LogGCOp(9c10c7f2454b4d91a90fe95d2af6b874): free 115943474 bytes of WAL
I20260812 06:18:29.536593 21810 log_reader.cc:385] T 9c10c7f2454b4d91a90fe95d2af6b874: removed 11 log segments from log reader
I20260812 06:18:29.536674 21810 log.cc:1079] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/9c10c7f2454b4d91a90fe95d2af6b874/wal-000000030 (ops 144-148)
I20260812 06:18:29.536726 21810 log.cc:1079] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/9c10c7f2454b4d91a90fe95d2af6b874/wal-000000031 (ops 149-153)
I20260812 06:18:29.536765 21810 log.cc:1079] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/9c10c7f2454b4d91a90fe95d2af6b874/wal-000000032 (ops 154-158)
I20260812 06:18:29.536801 21810 log.cc:1079] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/9c10c7f2454b4d91a90fe95d2af6b874/wal-000000033 (ops 159-163)
I20260812 06:18:29.536836 21810 log.cc:1079] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/9c10c7f2454b4d91a90fe95d2af6b874/wal-000000034 (ops 164-168)
I20260812 06:18:29.536871 21810 log.cc:1079] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/9c10c7f2454b4d91a90fe95d2af6b874/wal-000000035 (ops 169-173)
I20260812 06:18:29.536906 21810 log.cc:1079] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/9c10c7f2454b4d91a90fe95d2af6b874/wal-000000036 (ops 174-178)
I20260812 06:18:29.536942 21810 log.cc:1079] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/9c10c7f2454b4d91a90fe95d2af6b874/wal-000000037 (ops 179-183)
I20260812 06:18:29.536976 21810 log.cc:1079] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/9c10c7f2454b4d91a90fe95d2af6b874/wal-000000038 (ops 184-188)
I20260812 06:18:29.537011 21810 log.cc:1079] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/9c10c7f2454b4d91a90fe95d2af6b874/wal-000000039 (ops 189-193)
I20260812 06:18:29.537045 21810 log.cc:1079] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca: Deleting log segment in path: /tmp/dist-test-taskqGd4N3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515499903233-21365-0/minicluster-data/ts-0-root/wals/9c10c7f2454b4d91a90fe95d2af6b874/wal-000000040 (ops 194-198)
I20260812 06:18:29.562291 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: LogGCOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.026s	user 0.004s	sys 0.019s Metrics: {}
I20260812 06:18:29.562732 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling UndoDeltaBlockGCOp(9c10c7f2454b4d91a90fe95d2af6b874): 462 bytes on disk
I20260812 06:18:29.563160 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: UndoDeltaBlockGCOp(9c10c7f2454b4d91a90fe95d2af6b874) 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:18:29.563705 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=2.188937
I20260812 06:18:29.573100 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: FlushDeltaMemStoresOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.009s	user 0.002s	sys 0.006s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3593,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:29.573503 21920 maintenance_manager.cc:419] P 57424ec84e9a44ff9fb7dbc56ed334ca: Scheduling MajorDeltaCompactionOp(9c10c7f2454b4d91a90fe95d2af6b874): perf score=1.000000
I20260812 06:18:29.613328 21365 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.079s	user 0.002s	sys 0.000s
I20260812 06:18:29.613914 21365 tablet_server.cc:179] TabletServer@127.20.221.65:0 shutting down...
I20260812 06:18:29.701613 21810 maintenance_manager.cc:643] P 57424ec84e9a44ff9fb7dbc56ed334ca: MajorDeltaCompactionOp(9c10c7f2454b4d91a90fe95d2af6b874) complete. Timing: real 0.128s	user 0.087s	sys 0.040s Metrics: {"cfile_cache_hit":503,"cfile_cache_hit_bytes":20512409,"cfile_cache_miss":131,"cfile_cache_miss_bytes":8446885,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":308,"lbm_read_time_us":4324,"lbm_reads_lt_1ms":163,"lbm_write_time_us":26653,"lbm_writes_lt_1ms":643,"mutex_wait_us":38,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7936,"thread_start_us":71,"threads_started":1,"update_count":3000}
I20260812 06:18:29.702243 21365 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:29.702541 21365 tablet_replica.cc:333] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca: stopping tablet replica
I20260812 06:18:29.702661 21365 raft_consensus.cc:2243] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:29.702814 21365 raft_consensus.cc:2272] T 9c10c7f2454b4d91a90fe95d2af6b874 P 57424ec84e9a44ff9fb7dbc56ed334ca [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:29.717271 21365 tablet_server.cc:196] TabletServer@127.20.221.65:0 shutdown complete.
I20260812 06:18:29.752303 21365 master.cc:562] Master@127.20.221.126:42657 shutting down...
I20260812 06:18:29.755646 21365 raft_consensus.cc:2243] T 00000000000000000000000000000000 P e49bb6b263ac4c6daabdf68538316459 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:29.755836 21365 raft_consensus.cc:2272] T 00000000000000000000000000000000 P e49bb6b263ac4c6daabdf68538316459 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:29.755904 21365 tablet_replica.cc:333] T 00000000000000000000000000000000 P e49bb6b263ac4c6daabdf68538316459: stopping tablet replica
I20260812 06:18:29.768059 21365 master.cc:584] Master@127.20.221.126:42657 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (4907 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (9922 ms total)

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