[==========] 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:17:30.120594 22222 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.21.179.190:34769
I20260812 06:17:30.121502 22222 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:17:30.122020 22222 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:30.127472 22234 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:17:30.127614 22231 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:17:30.127660 22222 server_base.cc:1061] running on GCE node
W20260812 06:17:30.127728 22232 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:17:30.128111 22222 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:30.128189 22222 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:17:30.128235 22222 hybrid_clock.cc:648] HybridClock initialized: now 1786515450128232 us; error 0 us; skew 500 ppm
I20260812 06:17:30.129722 22222 webserver.cc:533] Webserver started at http://127.21.179.190:34375/ using document root <none> and password file <none>
I20260812 06:17:30.130159 22222 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:30.130208 22222 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:30.130409 22222 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:30.131814 22222 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450110720-22222-0/minicluster-data/master-0-root/instance:
uuid: "228372b79aea48008f7aa8024c2fb62d"
format_stamp: "Formatted at 2026-08-12 06:17:30 on dist-test-slave-2j7r"
I20260812 06:17:30.134874 22222 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.002s	sys 0.003s
I20260812 06:17:30.136621 22243 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:17:30.137524 22222 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:30.137620 22222 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450110720-22222-0/minicluster-data/master-0-root
uuid: "228372b79aea48008f7aa8024c2fb62d"
format_stamp: "Formatted at 2026-08-12 06:17:30 on dist-test-slave-2j7r"
I20260812 06:17:30.137694 22222 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450110720-22222-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450110720-22222-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450110720-22222-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:17:30.147239 22222 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:30.147710 22222 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:17:30.147835 22222 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:30.154440 22222 rpc_server.cc:307] RPC server started. Bound to: 127.21.179.190:34769
I20260812 06:17:30.154475 22349 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.21.179.190:34769 every 8 connection(s)
I20260812 06:17:30.156409 22355 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:17:30.161280 22355 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 228372b79aea48008f7aa8024c2fb62d: Bootstrap starting.
I20260812 06:17:30.163405 22355 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 228372b79aea48008f7aa8024c2fb62d: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:30.164206 22355 log.cc:826] T 00000000000000000000000000000000 P 228372b79aea48008f7aa8024c2fb62d: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:30.165700 22355 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 228372b79aea48008f7aa8024c2fb62d: No bootstrap required, opened a new log
I20260812 06:17:30.168313 22355 raft_consensus.cc:359] T 00000000000000000000000000000000 P 228372b79aea48008f7aa8024c2fb62d [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "228372b79aea48008f7aa8024c2fb62d" member_type: VOTER }
I20260812 06:17:30.168462 22355 raft_consensus.cc:385] T 00000000000000000000000000000000 P 228372b79aea48008f7aa8024c2fb62d [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:30.168536 22355 raft_consensus.cc:740] T 00000000000000000000000000000000 P 228372b79aea48008f7aa8024c2fb62d [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 228372b79aea48008f7aa8024c2fb62d, State: Initialized, Role: FOLLOWER
I20260812 06:17:30.169075 22355 consensus_queue.cc:260] T 00000000000000000000000000000000 P 228372b79aea48008f7aa8024c2fb62d [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: "228372b79aea48008f7aa8024c2fb62d" member_type: VOTER }
I20260812 06:17:30.169251 22355 raft_consensus.cc:399] T 00000000000000000000000000000000 P 228372b79aea48008f7aa8024c2fb62d [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:30.169315 22355 raft_consensus.cc:493] T 00000000000000000000000000000000 P 228372b79aea48008f7aa8024c2fb62d [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:30.169435 22355 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 228372b79aea48008f7aa8024c2fb62d [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:30.170138 22355 raft_consensus.cc:515] T 00000000000000000000000000000000 P 228372b79aea48008f7aa8024c2fb62d [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "228372b79aea48008f7aa8024c2fb62d" member_type: VOTER }
I20260812 06:17:30.170532 22355 leader_election.cc:304] T 00000000000000000000000000000000 P 228372b79aea48008f7aa8024c2fb62d [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: 228372b79aea48008f7aa8024c2fb62d; no voters: 
I20260812 06:17:30.170807 22355 leader_election.cc:290] T 00000000000000000000000000000000 P 228372b79aea48008f7aa8024c2fb62d [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:30.170909 22359 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 228372b79aea48008f7aa8024c2fb62d [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:30.171133 22359 raft_consensus.cc:697] T 00000000000000000000000000000000 P 228372b79aea48008f7aa8024c2fb62d [term 1 LEADER]: Becoming Leader. State: Replica: 228372b79aea48008f7aa8024c2fb62d, State: Running, Role: LEADER
I20260812 06:17:30.171520 22359 consensus_queue.cc:237] T 00000000000000000000000000000000 P 228372b79aea48008f7aa8024c2fb62d [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: "228372b79aea48008f7aa8024c2fb62d" member_type: VOTER }
I20260812 06:17:30.171679 22355 sys_catalog.cc:565] T 00000000000000000000000000000000 P 228372b79aea48008f7aa8024c2fb62d [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:30.173133 22365 sys_catalog.cc:455] T 00000000000000000000000000000000 P 228372b79aea48008f7aa8024c2fb62d [sys.catalog]: SysCatalogTable state changed. Reason: New leader 228372b79aea48008f7aa8024c2fb62d. Latest consensus state: current_term: 1 leader_uuid: "228372b79aea48008f7aa8024c2fb62d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "228372b79aea48008f7aa8024c2fb62d" member_type: VOTER } }
I20260812 06:17:30.173239 22365 sys_catalog.cc:458] T 00000000000000000000000000000000 P 228372b79aea48008f7aa8024c2fb62d [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:30.173532 22364 sys_catalog.cc:455] T 00000000000000000000000000000000 P 228372b79aea48008f7aa8024c2fb62d [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "228372b79aea48008f7aa8024c2fb62d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "228372b79aea48008f7aa8024c2fb62d" member_type: VOTER } }
I20260812 06:17:30.173597 22364 sys_catalog.cc:458] T 00000000000000000000000000000000 P 228372b79aea48008f7aa8024c2fb62d [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:30.173662 22222 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:17:30.175383 22384 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 228372b79aea48008f7aa8024c2fb62d: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:17:30.175444 22384 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:17:30.175526 22382 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:30.176232 22382 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:30.180842 22382 catalog_manager.cc:1383] Generated new cluster ID: e75d0b5780394639bfb11f69ae1f0b1a
I20260812 06:17:30.180902 22382 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:30.188275 22382 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:30.189378 22382 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:30.198518 22382 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 228372b79aea48008f7aa8024c2fb62d: Generated new TSK 0
I20260812 06:17:30.199095 22382 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:30.206060 22222 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:30.208491 22389 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:17:30.208531 22388 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:17:30.208730 22222 server_base.cc:1061] running on GCE node
W20260812 06:17:30.208707 22391 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:17:30.209035 22222 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:30.209105 22222 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:17:30.209141 22222 hybrid_clock.cc:648] HybridClock initialized: now 1786515450209141 us; error 0 us; skew 500 ppm
I20260812 06:17:30.209980 22222 webserver.cc:533] Webserver started at http://127.21.179.129:34323/ using document root <none> and password file <none>
I20260812 06:17:30.210143 22222 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:30.210188 22222 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:30.210261 22222 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:30.210619 22222 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450110720-22222-0/minicluster-data/ts-0-root/instance:
uuid: "e8f12b1da696495db5933daea91b37c6"
format_stamp: "Formatted at 2026-08-12 06:17:30 on dist-test-slave-2j7r"
I20260812 06:17:30.212074 22222 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:30.213016 22401 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:17:30.213260 22222 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:30.213330 22222 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450110720-22222-0/minicluster-data/ts-0-root
uuid: "e8f12b1da696495db5933daea91b37c6"
format_stamp: "Formatted at 2026-08-12 06:17:30 on dist-test-slave-2j7r"
I20260812 06:17:30.213397 22222 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450110720-22222-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450110720-22222-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450110720-22222-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:17:30.226323 22222 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:30.226670 22222 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:30.227058 22222 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:30.227833 22222 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:30.227886 22222 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:30.227931 22222 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:30.227959 22222 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:30.234071 22222 rpc_server.cc:307] RPC server started. Bound to: 127.21.179.129:38275
I20260812 06:17:30.234123 22527 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.21.179.129:38275 every 8 connection(s)
I20260812 06:17:30.243088 22529 heartbeater.cc:344] Connected to a master server at 127.21.179.190:34769
I20260812 06:17:30.243294 22529 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:30.243695 22529 heartbeater.cc:507] Master 127.21.179.190:34769 requested a full tablet report, sending...
I20260812 06:17:30.245059 22280 ts_manager.cc:194] Registered new tserver with Master: e8f12b1da696495db5933daea91b37c6 (127.21.179.129:38275)
I20260812 06:17:30.245687 22222 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011036796s
I20260812 06:17:30.246562 22280 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:47004
I20260812 06:17:30.254253 22280 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:47006:
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:17:30.267948 22464 tablet_service.cc:1511] Processing CreateTablet for tablet ab7baa46efb44de7a4000625b7097a9b (DEFAULT_TABLE table=heavy-update-compaction-test [id=26d3c4a743404fe9a027b0dcd6f24b31]), partition=
I20260812 06:17:30.268350 22464 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet ab7baa46efb44de7a4000625b7097a9b. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:30.270449 22554 tablet_bootstrap.cc:492] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6: Bootstrap starting.
I20260812 06:17:30.271270 22554 tablet_bootstrap.cc:654] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:30.272322 22554 tablet_bootstrap.cc:492] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6: No bootstrap required, opened a new log
I20260812 06:17:30.272414 22554 ts_tablet_manager.cc:1403] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:30.272876 22554 raft_consensus.cc:359] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e8f12b1da696495db5933daea91b37c6" member_type: VOTER last_known_addr { host: "127.21.179.129" port: 38275 } }
I20260812 06:17:30.272979 22554 raft_consensus.cc:385] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:30.273020 22554 raft_consensus.cc:740] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: e8f12b1da696495db5933daea91b37c6, State: Initialized, Role: FOLLOWER
I20260812 06:17:30.273164 22554 consensus_queue.cc:260] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6 [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: "e8f12b1da696495db5933daea91b37c6" member_type: VOTER last_known_addr { host: "127.21.179.129" port: 38275 } }
I20260812 06:17:30.273242 22554 raft_consensus.cc:399] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:30.273285 22554 raft_consensus.cc:493] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:30.273331 22554 raft_consensus.cc:3060] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:30.274382 22554 raft_consensus.cc:515] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e8f12b1da696495db5933daea91b37c6" member_type: VOTER last_known_addr { host: "127.21.179.129" port: 38275 } }
I20260812 06:17:30.274501 22554 leader_election.cc:304] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6 [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: e8f12b1da696495db5933daea91b37c6; no voters: 
I20260812 06:17:30.274681 22554 leader_election.cc:290] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:30.274791 22557 raft_consensus.cc:2804] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:30.274962 22557 raft_consensus.cc:697] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6 [term 1 LEADER]: Becoming Leader. State: Replica: e8f12b1da696495db5933daea91b37c6, State: Running, Role: LEADER
I20260812 06:17:30.275014 22554 ts_tablet_manager.cc:1434] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:17:30.275081 22557 consensus_queue.cc:237] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6 [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: "e8f12b1da696495db5933daea91b37c6" member_type: VOTER last_known_addr { host: "127.21.179.129" port: 38275 } }
I20260812 06:17:30.275357 22529 heartbeater.cc:499] Master 127.21.179.190:34769 was elected leader, sending a full tablet report...
I20260812 06:17:30.277987 22280 catalog_manager.cc:5719] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6 reported cstate change: term changed from 0 to 1, leader changed from <none> to e8f12b1da696495db5933daea91b37c6 (127.21.179.129). New cstate: current_term: 1 leader_uuid: "e8f12b1da696495db5933daea91b37c6" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e8f12b1da696495db5933daea91b37c6" member_type: VOTER last_known_addr { host: "127.21.179.129" port: 38275 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:30.341554 22222 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.059s	user 0.021s	sys 0.010s
I20260812 06:17:30.485129 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling FlushMRSOp(ab7baa46efb44de7a4000625b7097a9b): perf score=19.054940
I20260812 06:17:30.635499 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: FlushMRSOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.150s	user 0.115s	sys 0.033s Metrics: {"bytes_written":12307492,"cfile_init":1,"compiler_manager_pool.queue_time_us":225,"delete_count":0,"dirs.queue_time_us":26,"dirs.run_cpu_time_us":222,"dirs.run_wall_time_us":824,"drs_written":1,"lbm_read_time_us":99,"lbm_reads_lt_1ms":4,"lbm_write_time_us":34227,"lbm_writes_lt_1ms":767,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"thread_start_us":115,"threads_started":1,"update_count":1500}
I20260812 06:17:30.636538 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling LogGCOp(ab7baa46efb44de7a4000625b7097a9b): free 20743880 bytes of WAL
I20260812 06:17:30.636844 22414 log_reader.cc:385] T ab7baa46efb44de7a4000625b7097a9b: removed 2 log segments from log reader
I20260812 06:17:30.636907 22414 log.cc:1079] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/ab7baa46efb44de7a4000625b7097a9b/wal-000000001 (ops 1-6)
I20260812 06:17:30.636960 22414 log.cc:1079] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/ab7baa46efb44de7a4000625b7097a9b/wal-000000002 (ops 7-11)
I20260812 06:17:30.640458 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: LogGCOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.004s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:17:30.640841 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b): perf score=2.188937
I20260812 06:17:30.658773 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.018s	user 0.014s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5585,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:30.659157 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling UndoDeltaBlockGCOp(ab7baa46efb44de7a4000625b7097a9b): 16821647 bytes on disk
I20260812 06:17:30.659622 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: UndoDeltaBlockGCOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4}
I20260812 06:17:30.659996 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling MajorDeltaCompactionOp(ab7baa46efb44de7a4000625b7097a9b): perf score=1.000000
I20260812 06:17:30.786643 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: MajorDeltaCompactionOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.127s	user 0.085s	sys 0.039s Metrics: {"cfile_cache_miss":422,"cfile_cache_miss_bytes":20303020,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":638,"lbm_read_time_us":6405,"lbm_reads_lt_1ms":450,"lbm_write_time_us":22825,"lbm_writes_lt_1ms":433,"peak_mem_usage":49238594,"reinsert_count":0,"thread_start_us":282,"threads_started":5,"update_count":1950}
I20260812 06:17:30.787144 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b): perf score=10.126437
I20260812 06:17:30.826977 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.040s	user 0.015s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14018,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:30.827399 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b): perf score=2.188937
I20260812 06:17:30.842127 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5315,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:30.842510 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling MajorDeltaCompactionOp(ab7baa46efb44de7a4000625b7097a9b): perf score=1.000000
I20260812 06:17:30.963265 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: MajorDeltaCompactionOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.121s	user 0.096s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":922,"lbm_read_time_us":7858,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24786,"lbm_writes_lt_1ms":443,"mutex_wait_us":354,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10496,"update_count":2000}
I20260812 06:17:30.963704 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b): perf score=10.126437
I20260812 06:17:31.008010 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.044s	user 0.019s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15843,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:31.008421 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b): perf score=2.188937
I20260812 06:17:31.017901 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.009s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3662,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:31.018354 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling MajorDeltaCompactionOp(ab7baa46efb44de7a4000625b7097a9b): perf score=1.000000
I20260812 06:17:31.133037 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: MajorDeltaCompactionOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.115s	user 0.098s	sys 0.016s 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":117,"lbm_read_time_us":8069,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20462,"lbm_writes_lt_1ms":443,"mutex_wait_us":21,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":45568,"update_count":2000}
I20260812 06:17:31.133502 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b): perf score=10.126437
I20260812 06:17:31.181107 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.047s	user 0.027s	sys 0.010s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14368,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:31.181622 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b): perf score=2.188937
I20260812 06:17:31.196084 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.014s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5549,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:31.196508 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling MajorDeltaCompactionOp(ab7baa46efb44de7a4000625b7097a9b): perf score=1.000000
I20260812 06:17:31.336401 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: MajorDeltaCompactionOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.140s	user 0.090s	sys 0.045s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":888,"lbm_read_time_us":9192,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23672,"lbm_writes_lt_1ms":443,"mutex_wait_us":255,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:31.336928 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b): perf score=10.126437
I20260812 06:17:31.382782 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.046s	user 0.028s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16930,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:31.383201 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b): perf score=2.188937
I20260812 06:17:31.392719 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3621,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:31.393133 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling MajorDeltaCompactionOp(ab7baa46efb44de7a4000625b7097a9b): perf score=1.000000
I20260812 06:17:31.511237 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: MajorDeltaCompactionOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.118s	user 0.077s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":221,"lbm_read_time_us":8737,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25173,"lbm_writes_lt_1ms":443,"mutex_wait_us":44,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7936,"update_count":2000}
I20260812 06:17:31.511781 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b): perf score=10.126437
I20260812 06:17:31.551550 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.040s	user 0.017s	sys 0.013s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14415,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:31.551977 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b): perf score=2.188937
I20260812 06:17:31.566111 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.014s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5194,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:31.566635 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling MajorDeltaCompactionOp(ab7baa46efb44de7a4000625b7097a9b): perf score=1.000000
I20260812 06:17:31.687462 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: MajorDeltaCompactionOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.121s	user 0.077s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713270,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":196,"lbm_read_time_us":9363,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24842,"lbm_writes_lt_1ms":443,"mutex_wait_us":26,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":52992,"update_count":2000}
I20260812 06:17:31.687947 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b): perf score=10.126437
I20260812 06:17:31.728106 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.040s	user 0.032s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17841,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:31.728605 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b): perf score=2.188937
I20260812 06:17:31.744611 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.016s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6195,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:31.745267 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling MajorDeltaCompactionOp(ab7baa46efb44de7a4000625b7097a9b): perf score=1.000000
I20260812 06:17:31.860502 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: MajorDeltaCompactionOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.115s	user 0.098s	sys 0.017s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":232,"lbm_read_time_us":7491,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23560,"lbm_writes_lt_1ms":443,"mutex_wait_us":48,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":71808,"update_count":2000}
I20260812 06:17:31.860993 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b): perf score=10.126437
I20260812 06:17:31.911665 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.050s	user 0.020s	sys 0.022s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17316,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:31.912096 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b): perf score=2.188937
I20260812 06:17:31.921645 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.009s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3682,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:31.922014 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling FlushMRSOp(ab7baa46efb44de7a4000625b7097a9b): perf score=1.000000
I20260812 06:17:31.960552 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: FlushMRSOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.038s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1275444,"cfile_init":1,"dirs.queue_time_us":54,"dirs.run_cpu_time_us":198,"dirs.run_wall_time_us":1274,"drs_written":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1380,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:31.961370 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling LogGCOp(ab7baa46efb44de7a4000625b7097a9b): free 124710235 bytes of WAL
I20260812 06:17:31.961576 22414 log_reader.cc:385] T ab7baa46efb44de7a4000625b7097a9b: removed 12 log segments from log reader
I20260812 06:17:31.961620 22414 log.cc:1079] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/ab7baa46efb44de7a4000625b7097a9b/wal-000000003 (ops 12-16)
I20260812 06:17:31.961649 22414 log.cc:1079] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/ab7baa46efb44de7a4000625b7097a9b/wal-000000004 (ops 17-21)
I20260812 06:17:31.961680 22414 log.cc:1079] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/ab7baa46efb44de7a4000625b7097a9b/wal-000000005 (ops 22-26)
I20260812 06:17:31.961704 22414 log.cc:1079] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/ab7baa46efb44de7a4000625b7097a9b/wal-000000006 (ops 27-31)
I20260812 06:17:31.961735 22414 log.cc:1079] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/ab7baa46efb44de7a4000625b7097a9b/wal-000000007 (ops 32-36)
I20260812 06:17:31.961776 22414 log.cc:1079] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/ab7baa46efb44de7a4000625b7097a9b/wal-000000008 (ops 37-41)
I20260812 06:17:31.961807 22414 log.cc:1079] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/ab7baa46efb44de7a4000625b7097a9b/wal-000000009 (ops 42-46)
I20260812 06:17:31.961838 22414 log.cc:1079] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/ab7baa46efb44de7a4000625b7097a9b/wal-000000010 (ops 47-51)
I20260812 06:17:31.961869 22414 log.cc:1079] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/ab7baa46efb44de7a4000625b7097a9b/wal-000000011 (ops 52-56)
I20260812 06:17:31.961900 22414 log.cc:1079] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/ab7baa46efb44de7a4000625b7097a9b/wal-000000012 (ops 57-61)
I20260812 06:17:31.961932 22414 log.cc:1079] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/ab7baa46efb44de7a4000625b7097a9b/wal-000000013 (ops 62-66)
I20260812 06:17:31.961963 22414 log.cc:1079] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/ab7baa46efb44de7a4000625b7097a9b/wal-000000014 (ops 67-71)
I20260812 06:17:31.982360 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: LogGCOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.021s	user 0.000s	sys 0.020s Metrics: {}
I20260812 06:17:31.982736 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b): perf score=2.188937
I20260812 06:17:32.003397 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.021s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4956,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:32.003885 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b): perf score=2.188937
I20260812 06:17:32.012997 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3433,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:32.013437 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling MajorDeltaCompactionOp(ab7baa46efb44de7a4000625b7097a9b): perf score=1.000000
I20260812 06:17:32.209883 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: MajorDeltaCompactionOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.196s	user 0.139s	sys 0.056s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918335,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":2547,"lbm_read_time_us":14930,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33743,"lbm_writes_lt_1ms":643,"mutex_wait_us":839,"peak_mem_usage":75542472,"reinsert_count":0,"thread_start_us":111,"threads_started":1,"update_count":3000}
I20260812 06:17:32.210417 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling UndoDeltaBlockGCOp(ab7baa46efb44de7a4000625b7097a9b): 482 bytes on disk
I20260812 06:17:32.210865 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: UndoDeltaBlockGCOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4}
I20260812 06:17:32.211365 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b): perf score=14.095187
I20260812 06:17:32.254819 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.043s	user 0.026s	sys 0.016s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":19275,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:32.255287 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling MajorDeltaCompactionOp(ab7baa46efb44de7a4000625b7097a9b): perf score=1.000000
I20260812 06:17:32.397042 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: MajorDeltaCompactionOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.142s	user 0.082s	sys 0.053s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713151,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":207,"lbm_read_time_us":9987,"lbm_reads_lt_1ms":463,"lbm_write_time_us":22547,"lbm_writes_lt_1ms":443,"mutex_wait_us":21,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":42112,"update_count":2000}
I20260812 06:17:32.397562 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b): perf score=14.095187
I20260812 06:17:32.443377 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.046s	user 0.024s	sys 0.015s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18716,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:32.443857 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b): perf score=2.188937
I20260812 06:17:32.458915 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5702,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:32.459419 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling MajorDeltaCompactionOp(ab7baa46efb44de7a4000625b7097a9b): perf score=1.000000
I20260812 06:17:32.638031 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: MajorDeltaCompactionOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.178s	user 0.103s	sys 0.060s 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":647,"lbm_read_time_us":11250,"lbm_reads_lt_1ms":572,"lbm_write_time_us":24898,"lbm_writes_lt_1ms":543,"mutex_wait_us":338,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:17:32.638497 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b): perf score=14.095187
I20260812 06:17:32.687964 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.049s	user 0.030s	sys 0.016s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":22514,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:32.688477 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b): perf score=2.188937
I20260812 06:17:32.699707 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4254,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:32.700145 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling MajorDeltaCompactionOp(ab7baa46efb44de7a4000625b7097a9b): perf score=1.000000
I20260812 06:17:32.840787 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: MajorDeltaCompactionOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.140s	user 0.098s	sys 0.041s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":518,"lbm_read_time_us":10582,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27253,"lbm_writes_lt_1ms":543,"mutex_wait_us":308,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":22528,"update_count":2500}
I20260812 06:17:32.841347 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b): perf score=14.095187
I20260812 06:17:32.888521 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.047s	user 0.017s	sys 0.021s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18679,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:32.888981 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b): perf score=2.188937
I20260812 06:17:32.899773 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.011s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3892,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:32.900279 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling MajorDeltaCompactionOp(ab7baa46efb44de7a4000625b7097a9b): perf score=1.000000
I20260812 06:17:33.050974 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: MajorDeltaCompactionOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.151s	user 0.099s	sys 0.040s 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":623,"lbm_read_time_us":10961,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29274,"lbm_writes_lt_1ms":543,"mutex_wait_us":44,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6272,"update_count":2500}
I20260812 06:17:33.051487 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b): perf score=14.095187
I20260812 06:17:33.103853 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.052s	user 0.025s	sys 0.019s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20999,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:33.104346 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b): perf score=2.188937
I20260812 06:17:33.114526 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3804,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:33.115113 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling MajorDeltaCompactionOp(ab7baa46efb44de7a4000625b7097a9b): perf score=1.000000
I20260812 06:17:33.246615 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: MajorDeltaCompactionOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.131s	user 0.107s	sys 0.024s 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":600,"lbm_read_time_us":8795,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27503,"lbm_writes_lt_1ms":543,"mutex_wait_us":287,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2500}
I20260812 06:17:33.247268 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b): perf score=10.126437
I20260812 06:17:33.280072 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.033s	user 0.024s	sys 0.003s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13157,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:33.280637 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b): perf score=2.188937
I20260812 06:17:33.291393 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4155,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:33.291953 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling FlushMRSOp(ab7baa46efb44de7a4000625b7097a9b): perf score=1.000000
I20260812 06:17:33.320309 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: FlushMRSOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.028s	user 0.026s	sys 0.000s Metrics: {"bytes_written":1234477,"cfile_init":1,"dirs.queue_time_us":54,"dirs.run_cpu_time_us":187,"dirs.run_wall_time_us":1326,"drs_written":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1452,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:17:33.321020 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling LogGCOp(ab7baa46efb44de7a4000625b7097a9b): free 128867519 bytes of WAL
I20260812 06:17:33.321255 22414 log_reader.cc:385] T ab7baa46efb44de7a4000625b7097a9b: removed 13 log segments from log reader
I20260812 06:17:33.321313 22414 log.cc:1079] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/ab7baa46efb44de7a4000625b7097a9b/wal-000000015 (ops 72-76)
I20260812 06:17:33.321357 22414 log.cc:1079] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/ab7baa46efb44de7a4000625b7097a9b/wal-000000016 (ops 77-80)
I20260812 06:17:33.321388 22414 log.cc:1079] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/ab7baa46efb44de7a4000625b7097a9b/wal-000000017 (ops 81-85)
I20260812 06:17:33.321409 22414 log.cc:1079] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/ab7baa46efb44de7a4000625b7097a9b/wal-000000018 (ops 86-90)
I20260812 06:17:33.321436 22414 log.cc:1079] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/ab7baa46efb44de7a4000625b7097a9b/wal-000000019 (ops 91-95)
I20260812 06:17:33.321466 22414 log.cc:1079] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/ab7baa46efb44de7a4000625b7097a9b/wal-000000020 (ops 96-100)
I20260812 06:17:33.321498 22414 log.cc:1079] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/ab7baa46efb44de7a4000625b7097a9b/wal-000000021 (ops 101-105)
I20260812 06:17:33.321527 22414 log.cc:1079] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/ab7baa46efb44de7a4000625b7097a9b/wal-000000022 (ops 106-110)
I20260812 06:17:33.321554 22414 log.cc:1079] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/ab7baa46efb44de7a4000625b7097a9b/wal-000000023 (ops 111-114)
I20260812 06:17:33.321578 22414 log.cc:1079] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/ab7baa46efb44de7a4000625b7097a9b/wal-000000024 (ops 115-119)
I20260812 06:17:33.321606 22414 log.cc:1079] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/ab7baa46efb44de7a4000625b7097a9b/wal-000000025 (ops 120-124)
I20260812 06:17:33.321638 22414 log.cc:1079] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/ab7baa46efb44de7a4000625b7097a9b/wal-000000026 (ops 125-128)
I20260812 06:17:33.321666 22414 log.cc:1079] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/ab7baa46efb44de7a4000625b7097a9b/wal-000000027 (ops 129-133)
I20260812 06:17:33.348547 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: LogGCOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.027s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:17:33.348906 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b): perf score=3.181125
I20260812 06:17:33.359486 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":3982,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:33.359872 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling UndoDeltaBlockGCOp(ab7baa46efb44de7a4000625b7097a9b): 472 bytes on disk
I20260812 06:17:33.360230 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: UndoDeltaBlockGCOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4}
I20260812 06:17:33.360731 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b): perf score=2.188937
I20260812 06:17:33.369560 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3217,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:33.369901 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling MajorDeltaCompactionOp(ab7baa46efb44de7a4000625b7097a9b): perf score=1.000000
I20260812 06:17:33.533383 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: MajorDeltaCompactionOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.163s	user 0.111s	sys 0.050s 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":426,"lbm_read_time_us":12393,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33176,"lbm_writes_lt_1ms":643,"mutex_wait_us":18,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":5120,"thread_start_us":75,"threads_started":1,"update_count":3000}
I20260812 06:17:33.534180 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b): perf score=14.095187
I20260812 06:17:33.580416 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.046s	user 0.021s	sys 0.018s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19112,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:33.580976 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b): perf score=2.188937
I20260812 06:17:33.595889 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.015s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5299,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:33.596443 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling MajorDeltaCompactionOp(ab7baa46efb44de7a4000625b7097a9b): perf score=1.000000
I20260812 06:17:33.750027 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: MajorDeltaCompactionOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.153s	user 0.107s	sys 0.043s 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":167,"lbm_read_time_us":11885,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28574,"lbm_writes_lt_1ms":543,"mutex_wait_us":33,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5248,"update_count":2500}
I20260812 06:17:33.750674 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b): perf score=12.110812
I20260812 06:17:33.784641 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.034s	user 0.014s	sys 0.017s Metrics: {"bytes_written":13620267,"delete_count":0,"lbm_write_time_us":14049,"lbm_writes_lt_1ms":335,"reinsert_count":0,"update_count":1660}
I20260812 06:17:33.785169 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b): perf score=1.196750
I20260812 06:17:33.798528 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.013s	user 0.004s	sys 0.004s Metrics: {"bytes_written":2789855,"delete_count":0,"lbm_write_time_us":3490,"lbm_writes_lt_1ms":71,"reinsert_count":0,"update_count":340}
I20260812 06:17:33.799021 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling MajorDeltaCompactionOp(ab7baa46efb44de7a4000625b7097a9b): perf score=1.000000
I20260812 06:17:33.935861 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: MajorDeltaCompactionOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.137s	user 0.091s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713245,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":548,"lbm_read_time_us":8430,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24412,"lbm_writes_lt_1ms":443,"mutex_wait_us":320,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2000}
I20260812 06:17:33.936455 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b): perf score=11.118625
I20260812 06:17:33.970309 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.034s	user 0.017s	sys 0.015s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14868,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:33.970920 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b): perf score=2.188937
I20260812 06:17:33.984529 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.013s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4951,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:33.984997 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling MajorDeltaCompactionOp(ab7baa46efb44de7a4000625b7097a9b): perf score=1.000000
I20260812 06:17:34.111737 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: MajorDeltaCompactionOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.127s	user 0.089s	sys 0.034s 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":1117,"lbm_read_time_us":8692,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23571,"lbm_writes_lt_1ms":443,"mutex_wait_us":357,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10880,"update_count":2000}
I20260812 06:17:34.112437 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b): perf score=11.118625
I20260812 06:17:34.146211 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.034s	user 0.025s	sys 0.007s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":14131,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:17:34.146888 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b): perf score=2.188937
I20260812 06:17:34.166793 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.020s	user 0.005s	sys 0.005s Metrics: {"bytes_written":3733434,"delete_count":0,"lbm_write_time_us":4392,"lbm_writes_lt_1ms":94,"reinsert_count":0,"update_count":455}
I20260812 06:17:34.167313 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b): perf score=2.188937
I20260812 06:17:34.177990 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.011s	user 0.004s	sys 0.006s Metrics: {"bytes_written":4061634,"delete_count":0,"lbm_write_time_us":4262,"lbm_writes_lt_1ms":102,"reinsert_count":0,"update_count":495}
I20260812 06:17:34.178452 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling MajorDeltaCompactionOp(ab7baa46efb44de7a4000625b7097a9b): perf score=1.000000
I20260812 06:17:34.324014 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: MajorDeltaCompactionOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.145s	user 0.126s	sys 0.016s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":180,"lbm_read_time_us":9510,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29355,"lbm_writes_lt_1ms":543,"mutex_wait_us":1,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:17:34.324616 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b): perf score=11.118625
I20260812 06:17:34.365170 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.040s	user 0.024s	sys 0.016s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":14887,"lbm_writes_lt_1ms":313,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":1550}
I20260812 06:17:34.365769 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b): perf score=2.188937
I20260812 06:17:34.380713 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.015s	user 0.005s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3618,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:34.381199 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b): perf score=2.188937
I20260812 06:17:34.390563 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3606,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:34.391043 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling MajorDeltaCompactionOp(ab7baa46efb44de7a4000625b7097a9b): perf score=1.000000
I20260812 06:17:34.532629 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: MajorDeltaCompactionOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.141s	user 0.113s	sys 0.024s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815793,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":145,"lbm_read_time_us":8629,"lbm_reads_lt_1ms":573,"lbm_write_time_us":28259,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":79232,"update_count":2500}
I20260812 06:17:34.533504 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b): perf score=12.110812
I20260812 06:17:34.573331 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.040s	user 0.022s	sys 0.017s Metrics: {"bytes_written":13620265,"delete_count":0,"lbm_write_time_us":16756,"lbm_writes_lt_1ms":335,"reinsert_count":0,"update_count":1660}
I20260812 06:17:34.574074 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b): perf score=1.196750
I20260812 06:17:34.594408 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.020s	user 0.004s	sys 0.004s Metrics: {"bytes_written":2994984,"delete_count":0,"lbm_write_time_us":3062,"lbm_writes_lt_1ms":76,"reinsert_count":0,"update_count":365}
I20260812 06:17:34.594879 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b): perf score=2.188937
I20260812 06:17:34.604463 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.009s	user 0.005s	sys 0.003s Metrics: {"bytes_written":3897534,"delete_count":0,"lbm_write_time_us":3817,"lbm_writes_lt_1ms":98,"reinsert_count":0,"update_count":475}
I20260812 06:17:34.604861 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling FlushMRSOp(ab7baa46efb44de7a4000625b7097a9b): perf score=1.000000
I20260812 06:17:34.637506 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: FlushMRSOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.032s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1234477,"cfile_init":1,"dirs.queue_time_us":58,"dirs.run_cpu_time_us":219,"dirs.run_wall_time_us":1386,"drs_written":1,"lbm_read_time_us":35,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1876,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:17:34.638144 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling LogGCOp(ab7baa46efb44de7a4000625b7097a9b): free 120553647 bytes of WAL
I20260812 06:17:34.638366 22414 log_reader.cc:385] T ab7baa46efb44de7a4000625b7097a9b: removed 12 log segments from log reader
I20260812 06:17:34.638412 22414 log.cc:1079] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/ab7baa46efb44de7a4000625b7097a9b/wal-000000028 (ops 134-138)
I20260812 06:17:34.638442 22414 log.cc:1079] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/ab7baa46efb44de7a4000625b7097a9b/wal-000000029 (ops 139-142)
I20260812 06:17:34.638474 22414 log.cc:1079] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/ab7baa46efb44de7a4000625b7097a9b/wal-000000030 (ops 143-147)
I20260812 06:17:34.638505 22414 log.cc:1079] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/ab7baa46efb44de7a4000625b7097a9b/wal-000000031 (ops 148-152)
I20260812 06:17:34.638537 22414 log.cc:1079] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/ab7baa46efb44de7a4000625b7097a9b/wal-000000032 (ops 153-157)
I20260812 06:17:34.638568 22414 log.cc:1079] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/ab7baa46efb44de7a4000625b7097a9b/wal-000000033 (ops 158-162)
I20260812 06:17:34.638599 22414 log.cc:1079] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/ab7baa46efb44de7a4000625b7097a9b/wal-000000034 (ops 163-167)
I20260812 06:17:34.638630 22414 log.cc:1079] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/ab7baa46efb44de7a4000625b7097a9b/wal-000000035 (ops 168-172)
I20260812 06:17:34.638661 22414 log.cc:1079] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/ab7baa46efb44de7a4000625b7097a9b/wal-000000036 (ops 173-177)
I20260812 06:17:34.638691 22414 log.cc:1079] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/ab7baa46efb44de7a4000625b7097a9b/wal-000000037 (ops 178-182)
I20260812 06:17:34.638722 22414 log.cc:1079] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/ab7baa46efb44de7a4000625b7097a9b/wal-000000038 (ops 183-186)
I20260812 06:17:34.638753 22414 log.cc:1079] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/ab7baa46efb44de7a4000625b7097a9b/wal-000000039 (ops 187-191)
I20260812 06:17:34.660152 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: LogGCOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.022s	user 0.000s	sys 0.019s Metrics: {}
I20260812 06:17:34.660552 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling UndoDeltaBlockGCOp(ab7baa46efb44de7a4000625b7097a9b): 472 bytes on disk
I20260812 06:17:34.661132 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: UndoDeltaBlockGCOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4}
I20260812 06:17:34.661659 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b): perf score=3.181125
I20260812 06:17:34.678583 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.017s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":6759,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:34.678954 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b): perf score=2.188937
I20260812 06:17:34.687803 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: FlushDeltaMemStoresOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.009s	user 0.000s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3281,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:34.688175 22531 maintenance_manager.cc:419] P e8f12b1da696495db5933daea91b37c6: Scheduling MajorDeltaCompactionOp(ab7baa46efb44de7a4000625b7097a9b): perf score=1.000000
I20260812 06:17:34.771051 22222 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.429s	user 1.695s	sys 0.089s
I20260812 06:17:34.883658 22222 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.112s	user 0.003s	sys 0.000s
I20260812 06:17:34.884269 22222 tablet_server.cc:179] TabletServer@127.21.179.129:0 shutting down...
I20260812 06:17:34.901310 22414 maintenance_manager.cc:643] P e8f12b1da696495db5933daea91b37c6: MajorDeltaCompactionOp(ab7baa46efb44de7a4000625b7097a9b) complete. Timing: real 0.213s	user 0.159s	sys 0.054s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":33020830,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":304,"lbm_read_time_us":13931,"lbm_reads_lt_1ms":771,"lbm_write_time_us":38808,"lbm_writes_lt_1ms":743,"mutex_wait_us":24,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":26112,"thread_start_us":62,"threads_started":1,"update_count":3500}
I20260812 06:17:34.902295 22222 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:34.902773 22222 tablet_replica.cc:333] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6: stopping tablet replica
I20260812 06:17:34.902984 22222 raft_consensus.cc:2243] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:34.903191 22222 raft_consensus.cc:2272] T ab7baa46efb44de7a4000625b7097a9b P e8f12b1da696495db5933daea91b37c6 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:34.919224 22222 tablet_server.cc:196] TabletServer@127.21.179.129:0 shutdown complete.
I20260812 06:17:34.958178 22222 master.cc:562] Master@127.21.179.190:34769 shutting down...
I20260812 06:17:34.961400 22222 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 228372b79aea48008f7aa8024c2fb62d [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:34.961560 22222 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 228372b79aea48008f7aa8024c2fb62d [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:34.961637 22222 tablet_replica.cc:333] T 00000000000000000000000000000000 P 228372b79aea48008f7aa8024c2fb62d: stopping tablet replica
I20260812 06:17:34.973680 22222 master.cc:584] Master@127.21.179.190:34769 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (4923 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:35.043951 22222 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.21.179.190:43063
I20260812 06:17:35.044340 22222 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:35.046252 22591 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:17:35.046260 22597 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:17:35.046391 22594 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:17:35.046497 22222 server_base.cc:1061] running on GCE node
I20260812 06:17:35.046628 22222 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:35.046662 22222 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:17:35.046676 22222 hybrid_clock.cc:648] HybridClock initialized: now 1786515455046676 us; error 0 us; skew 500 ppm
I20260812 06:17:35.047443 22222 webserver.cc:533] Webserver started at http://127.21.179.190:40957/ using document root <none> and password file <none>
I20260812 06:17:35.047569 22222 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:35.047603 22222 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:35.047654 22222 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:35.047976 22222 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450110720-22222-0/minicluster-data/master-0-root/instance:
uuid: "609b4caac8af45b2a4522f3899de40ff"
format_stamp: "Formatted at 2026-08-12 06:17:35 on dist-test-slave-2j7r"
I20260812 06:17:35.049463 22222 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:17:35.050294 22604 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:17:35.050539 22222 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:17:35.050608 22222 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450110720-22222-0/minicluster-data/master-0-root
uuid: "609b4caac8af45b2a4522f3899de40ff"
format_stamp: "Formatted at 2026-08-12 06:17:35 on dist-test-slave-2j7r"
I20260812 06:17:35.050676 22222 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450110720-22222-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450110720-22222-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450110720-22222-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:17:35.056108 22222 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:35.056404 22222 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:35.060290 22222 rpc_server.cc:307] RPC server started. Bound to: 127.21.179.190:43063
I20260812 06:17:35.068676 22700 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:17:35.076630 22699 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.21.179.190:43063 every 8 connection(s)
I20260812 06:17:35.079449 22700 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 609b4caac8af45b2a4522f3899de40ff: Bootstrap starting.
I20260812 06:17:35.080219 22700 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 609b4caac8af45b2a4522f3899de40ff: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:35.081177 22700 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 609b4caac8af45b2a4522f3899de40ff: No bootstrap required, opened a new log
I20260812 06:17:35.081564 22700 raft_consensus.cc:359] T 00000000000000000000000000000000 P 609b4caac8af45b2a4522f3899de40ff [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "609b4caac8af45b2a4522f3899de40ff" member_type: VOTER }
I20260812 06:17:35.081645 22700 raft_consensus.cc:385] T 00000000000000000000000000000000 P 609b4caac8af45b2a4522f3899de40ff [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:35.081678 22700 raft_consensus.cc:740] T 00000000000000000000000000000000 P 609b4caac8af45b2a4522f3899de40ff [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 609b4caac8af45b2a4522f3899de40ff, State: Initialized, Role: FOLLOWER
I20260812 06:17:35.081823 22700 consensus_queue.cc:260] T 00000000000000000000000000000000 P 609b4caac8af45b2a4522f3899de40ff [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: "609b4caac8af45b2a4522f3899de40ff" member_type: VOTER }
I20260812 06:17:35.081893 22700 raft_consensus.cc:399] T 00000000000000000000000000000000 P 609b4caac8af45b2a4522f3899de40ff [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:35.081928 22700 raft_consensus.cc:493] T 00000000000000000000000000000000 P 609b4caac8af45b2a4522f3899de40ff [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:35.081977 22700 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 609b4caac8af45b2a4522f3899de40ff [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:35.082633 22700 raft_consensus.cc:515] T 00000000000000000000000000000000 P 609b4caac8af45b2a4522f3899de40ff [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "609b4caac8af45b2a4522f3899de40ff" member_type: VOTER }
I20260812 06:17:35.082752 22700 leader_election.cc:304] T 00000000000000000000000000000000 P 609b4caac8af45b2a4522f3899de40ff [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: 609b4caac8af45b2a4522f3899de40ff; no voters: 
I20260812 06:17:35.082933 22700 leader_election.cc:290] T 00000000000000000000000000000000 P 609b4caac8af45b2a4522f3899de40ff [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:35.083032 22707 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 609b4caac8af45b2a4522f3899de40ff [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:35.083261 22707 raft_consensus.cc:697] T 00000000000000000000000000000000 P 609b4caac8af45b2a4522f3899de40ff [term 1 LEADER]: Becoming Leader. State: Replica: 609b4caac8af45b2a4522f3899de40ff, State: Running, Role: LEADER
I20260812 06:17:35.083366 22700 sys_catalog.cc:565] T 00000000000000000000000000000000 P 609b4caac8af45b2a4522f3899de40ff [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:35.083391 22707 consensus_queue.cc:237] T 00000000000000000000000000000000 P 609b4caac8af45b2a4522f3899de40ff [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: "609b4caac8af45b2a4522f3899de40ff" member_type: VOTER }
I20260812 06:17:35.083784 22710 sys_catalog.cc:455] T 00000000000000000000000000000000 P 609b4caac8af45b2a4522f3899de40ff [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "609b4caac8af45b2a4522f3899de40ff" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "609b4caac8af45b2a4522f3899de40ff" member_type: VOTER } }
I20260812 06:17:35.083890 22710 sys_catalog.cc:458] T 00000000000000000000000000000000 P 609b4caac8af45b2a4522f3899de40ff [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:35.083796 22711 sys_catalog.cc:455] T 00000000000000000000000000000000 P 609b4caac8af45b2a4522f3899de40ff [sys.catalog]: SysCatalogTable state changed. Reason: New leader 609b4caac8af45b2a4522f3899de40ff. Latest consensus state: current_term: 1 leader_uuid: "609b4caac8af45b2a4522f3899de40ff" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "609b4caac8af45b2a4522f3899de40ff" member_type: VOTER } }
I20260812 06:17:35.084074 22711 sys_catalog.cc:458] T 00000000000000000000000000000000 P 609b4caac8af45b2a4522f3899de40ff [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:35.084533 22714 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:35.085274 22714 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:35.085472 22222 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:35.086968 22714 catalog_manager.cc:1383] Generated new cluster ID: 498e3fa34ee44472bdea0a4a38e8407f
I20260812 06:17:35.087018 22714 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:35.106513 22714 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:35.106983 22714 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:35.116410 22714 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 609b4caac8af45b2a4522f3899de40ff: Generated new TSK 0
I20260812 06:17:35.116540 22714 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:35.117514 22222 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:35.119014 22736 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:17:35.119155 22740 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:17:35.119194 22742 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:17:35.119268 22222 server_base.cc:1061] running on GCE node
I20260812 06:17:35.119441 22222 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:35.119478 22222 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:17:35.119493 22222 hybrid_clock.cc:648] HybridClock initialized: now 1786515455119492 us; error 0 us; skew 500 ppm
I20260812 06:17:35.120234 22222 webserver.cc:533] Webserver started at http://127.21.179.129:46439/ using document root <none> and password file <none>
I20260812 06:17:35.120358 22222 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:35.120395 22222 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:35.120445 22222 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:35.120718 22222 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450110720-22222-0/minicluster-data/ts-0-root/instance:
uuid: "45469f189fce4cff9e0cd7c01435d990"
format_stamp: "Formatted at 2026-08-12 06:17:35 on dist-test-slave-2j7r"
I20260812 06:17:35.122040 22222 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:17:35.122870 22752 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:17:35.123080 22222 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:17:35.123139 22222 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450110720-22222-0/minicluster-data/ts-0-root
uuid: "45469f189fce4cff9e0cd7c01435d990"
format_stamp: "Formatted at 2026-08-12 06:17:35 on dist-test-slave-2j7r"
I20260812 06:17:35.123188 22222 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450110720-22222-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450110720-22222-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450110720-22222-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:17:35.135352 22222 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:35.135594 22222 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:35.135812 22222 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:35.136166 22222 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:35.136198 22222 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:35.136225 22222 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:35.136240 22222 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:35.140167 22222 rpc_server.cc:307] RPC server started. Bound to: 127.21.179.129:41111
I20260812 06:17:35.140219 22885 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.21.179.129:41111 every 8 connection(s)
I20260812 06:17:35.148772 22887 heartbeater.cc:344] Connected to a master server at 127.21.179.190:43063
I20260812 06:17:35.148872 22887 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:35.149060 22887 heartbeater.cc:507] Master 127.21.179.190:43063 requested a full tablet report, sending...
I20260812 06:17:35.149653 22629 ts_manager.cc:194] Registered new tserver with Master: 45469f189fce4cff9e0cd7c01435d990 (127.21.179.129:41111)
I20260812 06:17:35.150334 22629 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:53240
I20260812 06:17:35.150439 22222 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.009890067s
I20260812 06:17:35.156406 22629 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:53248:
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:17:35.163800 22799 tablet_service.cc:1511] Processing CreateTablet for tablet 787ecaa338d349a6a241ec85a9837eac (DEFAULT_TABLE table=heavy-update-compaction-test [id=0977b35614684554bd822e134a98ea33]), partition=
I20260812 06:17:35.164026 22799 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 787ecaa338d349a6a241ec85a9837eac. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:35.165853 22918 tablet_bootstrap.cc:492] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990: Bootstrap starting.
I20260812 06:17:35.166664 22918 tablet_bootstrap.cc:654] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:35.167601 22918 tablet_bootstrap.cc:492] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990: No bootstrap required, opened a new log
I20260812 06:17:35.167678 22918 ts_tablet_manager.cc:1403] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:17:35.168040 22918 raft_consensus.cc:359] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "45469f189fce4cff9e0cd7c01435d990" member_type: VOTER last_known_addr { host: "127.21.179.129" port: 41111 } }
I20260812 06:17:35.168118 22918 raft_consensus.cc:385] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:35.168146 22918 raft_consensus.cc:740] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 45469f189fce4cff9e0cd7c01435d990, State: Initialized, Role: FOLLOWER
I20260812 06:17:35.168265 22918 consensus_queue.cc:260] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990 [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: "45469f189fce4cff9e0cd7c01435d990" member_type: VOTER last_known_addr { host: "127.21.179.129" port: 41111 } }
I20260812 06:17:35.168339 22918 raft_consensus.cc:399] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:35.168378 22918 raft_consensus.cc:493] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:35.168424 22918 raft_consensus.cc:3060] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:35.169073 22918 raft_consensus.cc:515] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "45469f189fce4cff9e0cd7c01435d990" member_type: VOTER last_known_addr { host: "127.21.179.129" port: 41111 } }
I20260812 06:17:35.169229 22918 leader_election.cc:304] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990 [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: 45469f189fce4cff9e0cd7c01435d990; no voters: 
I20260812 06:17:35.169410 22918 leader_election.cc:290] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:35.169498 22923 raft_consensus.cc:2804] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:35.169646 22923 raft_consensus.cc:697] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990 [term 1 LEADER]: Becoming Leader. State: Replica: 45469f189fce4cff9e0cd7c01435d990, State: Running, Role: LEADER
I20260812 06:17:35.169783 22918 ts_tablet_manager.cc:1434] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:17:35.169817 22923 consensus_queue.cc:237] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990 [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: "45469f189fce4cff9e0cd7c01435d990" member_type: VOTER last_known_addr { host: "127.21.179.129" port: 41111 } }
I20260812 06:17:35.169862 22887 heartbeater.cc:499] Master 127.21.179.190:43063 was elected leader, sending a full tablet report...
I20260812 06:17:35.171018 22629 catalog_manager.cc:5719] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990 reported cstate change: term changed from 0 to 1, leader changed from <none> to 45469f189fce4cff9e0cd7c01435d990 (127.21.179.129). New cstate: current_term: 1 leader_uuid: "45469f189fce4cff9e0cd7c01435d990" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "45469f189fce4cff9e0cd7c01435d990" member_type: VOTER last_known_addr { host: "127.21.179.129" port: 41111 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:35.222410 22222 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.048s	user 0.009s	sys 0.012s
I20260812 06:17:35.391168 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling FlushMRSOp(787ecaa338d349a6a241ec85a9837eac): perf score=23.023690
I20260812 06:17:35.542610 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: FlushMRSOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.151s	user 0.097s	sys 0.052s Metrics: {"bytes_written":13989483,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":48,"dirs.run_cpu_time_us":173,"dirs.run_wall_time_us":773,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":38884,"lbm_writes_lt_1ms":898,"mutex_wait_us":444,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"spinlock_wait_cycles":2688,"update_count":1705}
I20260812 06:17:35.543183 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling LogGCOp(787ecaa338d349a6a241ec85a9837eac): free 20743880 bytes of WAL
I20260812 06:17:35.543418 22760 log_reader.cc:385] T 787ecaa338d349a6a241ec85a9837eac: removed 2 log segments from log reader
I20260812 06:17:35.543465 22760 log.cc:1079] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/787ecaa338d349a6a241ec85a9837eac/wal-000000001 (ops 1-6)
I20260812 06:17:35.543495 22760 log.cc:1079] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/787ecaa338d349a6a241ec85a9837eac/wal-000000002 (ops 7-11)
I20260812 06:17:35.547001 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: LogGCOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.004s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:17:35.547544 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac): perf score=1.196750
I20260812 06:17:35.556344 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.009s	user 0.003s	sys 0.004s Metrics: {"bytes_written":3323188,"delete_count":0,"lbm_write_time_us":3051,"lbm_writes_lt_1ms":84,"reinsert_count":0,"update_count":405}
I20260812 06:17:35.556746 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling UndoDeltaBlockGCOp(787ecaa338d349a6a241ec85a9837eac): 20513811 bytes on disk
I20260812 06:17:35.557181 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: UndoDeltaBlockGCOp(787ecaa338d349a6a241ec85a9837eac) 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:17:35.557577 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac): perf score=2.188937
I20260812 06:17:35.565447 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.008s	user 0.007s	sys 0.000s Metrics: {"bytes_written":3200105,"delete_count":0,"lbm_write_time_us":2704,"lbm_writes_lt_1ms":81,"reinsert_count":0,"update_count":390}
I20260812 06:17:35.565784 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling MajorDeltaCompactionOp(787ecaa338d349a6a241ec85a9837eac): perf score=1.000000
I20260812 06:17:35.714874 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: MajorDeltaCompactionOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.149s	user 0.081s	sys 0.065s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815771,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":394,"lbm_read_time_us":10559,"lbm_reads_lt_1ms":569,"lbm_write_time_us":25210,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1536,"thread_start_us":302,"threads_started":5,"update_count":2500}
I20260812 06:17:35.715456 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac): perf score=11.118625
I20260812 06:17:35.746829 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.031s	user 0.017s	sys 0.013s Metrics: {"bytes_written":12717738,"delete_count":0,"lbm_write_time_us":13249,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:35.747318 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac): perf score=2.188937
I20260812 06:17:35.766817 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.019s	user 0.007s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4461,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:35.767396 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac): perf score=2.188937
I20260812 06:17:35.776840 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3620,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.777334 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling MajorDeltaCompactionOp(787ecaa338d349a6a241ec85a9837eac): perf score=1.000000
I20260812 06:17:35.919363 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: MajorDeltaCompactionOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.142s	user 0.113s	sys 0.024s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815797,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1366,"lbm_read_time_us":11019,"lbm_reads_lt_1ms":573,"lbm_write_time_us":24655,"lbm_writes_lt_1ms":543,"mutex_wait_us":329,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3584,"update_count":2500}
I20260812 06:17:35.919915 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac): perf score=11.118625
I20260812 06:17:35.956787 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.037s	user 0.030s	sys 0.003s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16068,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:35.957391 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac): perf score=2.188937
I20260812 06:17:35.980150 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.022s	user 0.002s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4414,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:35.980613 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac): perf score=2.188937
I20260812 06:17:35.990015 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3565,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.990408 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling MajorDeltaCompactionOp(787ecaa338d349a6a241ec85a9837eac): perf score=1.000000
I20260812 06:17:36.137574 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: MajorDeltaCompactionOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.147s	user 0.111s	sys 0.028s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815794,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":550,"lbm_read_time_us":10319,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29526,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11776,"update_count":2500}
I20260812 06:17:36.138197 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac): perf score=14.095187
I20260812 06:17:36.201124 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.063s	user 0.030s	sys 0.032s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":27166,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:36.201794 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac): perf score=2.188937
I20260812 06:17:36.225734 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.024s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4825,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:36.226150 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac): perf score=2.188937
I20260812 06:17:36.235836 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.010s	user 0.005s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3984,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:36.236227 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling MajorDeltaCompactionOp(787ecaa338d349a6a241ec85a9837eac): perf score=1.000000
I20260812 06:17:36.383699 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: MajorDeltaCompactionOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.147s	user 0.103s	sys 0.044s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918217,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":132,"lbm_read_time_us":11261,"lbm_reads_lt_1ms":673,"lbm_write_time_us":31196,"lbm_writes_lt_1ms":643,"mutex_wait_us":21,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7680,"update_count":3000}
I20260812 06:17:36.384577 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac): perf score=14.095187
I20260812 06:17:36.426998 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.042s	user 0.028s	sys 0.012s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":18563,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:36.427502 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac): perf score=2.188937
I20260812 06:17:36.437136 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.009s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3708,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:36.437521 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling MajorDeltaCompactionOp(787ecaa338d349a6a241ec85a9837eac): perf score=1.000000
I20260812 06:17:36.600461 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: MajorDeltaCompactionOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.163s	user 0.119s	sys 0.032s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815681,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":563,"lbm_read_time_us":11017,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29592,"lbm_writes_lt_1ms":543,"mutex_wait_us":318,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":25344,"update_count":2500}
I20260812 06:17:36.601176 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac): perf score=14.095187
I20260812 06:17:36.648003 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.047s	user 0.017s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18355,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:36.648524 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling FlushMRSOp(787ecaa338d349a6a241ec85a9837eac): perf score=1.000000
I20260812 06:17:36.696259 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: FlushMRSOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.048s	user 0.026s	sys 0.000s Metrics: {"bytes_written":1275444,"cfile_init":1,"dirs.queue_time_us":61,"dirs.run_cpu_time_us":232,"dirs.run_wall_time_us":1345,"drs_written":1,"lbm_read_time_us":35,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1378,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:36.696904 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling LogGCOp(787ecaa338d349a6a241ec85a9837eac): free 120553334 bytes of WAL
I20260812 06:17:36.697204 22760 log_reader.cc:385] T 787ecaa338d349a6a241ec85a9837eac: removed 12 log segments from log reader
I20260812 06:17:36.697293 22760 log.cc:1079] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/787ecaa338d349a6a241ec85a9837eac/wal-000000003 (ops 12-16)
I20260812 06:17:36.697350 22760 log.cc:1079] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/787ecaa338d349a6a241ec85a9837eac/wal-000000004 (ops 17-21)
I20260812 06:17:36.697384 22760 log.cc:1079] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/787ecaa338d349a6a241ec85a9837eac/wal-000000005 (ops 22-26)
I20260812 06:17:36.697415 22760 log.cc:1079] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/787ecaa338d349a6a241ec85a9837eac/wal-000000006 (ops 27-30)
I20260812 06:17:36.697445 22760 log.cc:1079] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/787ecaa338d349a6a241ec85a9837eac/wal-000000007 (ops 31-35)
I20260812 06:17:36.697476 22760 log.cc:1079] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/787ecaa338d349a6a241ec85a9837eac/wal-000000008 (ops 36-40)
I20260812 06:17:36.697507 22760 log.cc:1079] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/787ecaa338d349a6a241ec85a9837eac/wal-000000009 (ops 41-45)
I20260812 06:17:36.697537 22760 log.cc:1079] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/787ecaa338d349a6a241ec85a9837eac/wal-000000010 (ops 46-50)
I20260812 06:17:36.697568 22760 log.cc:1079] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/787ecaa338d349a6a241ec85a9837eac/wal-000000011 (ops 51-55)
I20260812 06:17:36.697599 22760 log.cc:1079] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/787ecaa338d349a6a241ec85a9837eac/wal-000000012 (ops 56-60)
I20260812 06:17:36.697630 22760 log.cc:1079] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/787ecaa338d349a6a241ec85a9837eac/wal-000000013 (ops 61-64)
I20260812 06:17:36.697661 22760 log.cc:1079] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/787ecaa338d349a6a241ec85a9837eac/wal-000000014 (ops 65-69)
I20260812 06:17:36.719260 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: LogGCOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.022s	user 0.001s	sys 0.019s Metrics: {}
I20260812 06:17:36.719688 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling UndoDeltaBlockGCOp(787ecaa338d349a6a241ec85a9837eac): 482 bytes on disk
I20260812 06:17:36.720124 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: UndoDeltaBlockGCOp(787ecaa338d349a6a241ec85a9837eac) 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:17:36.720592 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac): perf score=7.149875
I20260812 06:17:36.743853 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.023s	user 0.018s	sys 0.003s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":9794,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:17:36.744319 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling LogGCOp(787ecaa338d349a6a241ec85a9837eac): free 8767174 bytes of WAL
I20260812 06:17:36.744511 22760 log_reader.cc:385] T 787ecaa338d349a6a241ec85a9837eac: removed 1 log segments from log reader
I20260812 06:17:36.744554 22760 log.cc:1079] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/787ecaa338d349a6a241ec85a9837eac/wal-000000015 (ops 70-74)
I20260812 06:17:36.746124 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: LogGCOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.002s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:17:36.746400 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac): perf score=2.188937
I20260812 06:17:36.757968 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.011s	user 0.004s	sys 0.006s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4041,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:36.758386 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling MajorDeltaCompactionOp(787ecaa338d349a6a241ec85a9837eac): perf score=1.000000
I20260812 06:17:36.960289 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: MajorDeltaCompactionOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.202s	user 0.130s	sys 0.072s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":33020618,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":138,"lbm_read_time_us":14513,"lbm_reads_lt_1ms":765,"lbm_write_time_us":36662,"lbm_writes_lt_1ms":743,"mutex_wait_us":21,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":28928,"thread_start_us":101,"threads_started":1,"update_count":3500}
I20260812 06:17:36.960901 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac): perf score=18.063937
I20260812 06:17:37.013181 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.052s	user 0.028s	sys 0.024s Metrics: {"bytes_written":20512324,"delete_count":0,"lbm_write_time_us":23513,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:37.013820 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac): perf score=2.188937
I20260812 06:17:37.037256 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.023s	user 0.008s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4220,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:37.037699 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac): perf score=2.188937
I20260812 06:17:37.047518 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.010s	user 0.001s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3745,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:37.048084 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling MajorDeltaCompactionOp(787ecaa338d349a6a241ec85a9837eac): perf score=1.000000
I20260812 06:17:37.237736 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: MajorDeltaCompactionOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.189s	user 0.145s	sys 0.044s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":33020635,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":804,"lbm_read_time_us":15151,"lbm_reads_lt_1ms":773,"lbm_write_time_us":39929,"lbm_writes_lt_1ms":743,"mutex_wait_us":20,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":13696,"update_count":3500}
I20260812 06:17:37.238354 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac): perf score=14.095187
I20260812 06:17:37.289340 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.051s	user 0.038s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22507,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:37.289916 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac): perf score=2.188937
I20260812 06:17:37.307192 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.017s	user 0.009s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6214,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:37.307617 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling MajorDeltaCompactionOp(787ecaa338d349a6a241ec85a9837eac): perf score=1.000000
I20260812 06:17:37.460809 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: MajorDeltaCompactionOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.153s	user 0.099s	sys 0.049s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":808,"lbm_read_time_us":8989,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30594,"lbm_writes_lt_1ms":543,"mutex_wait_us":60,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":22016,"update_count":2500}
I20260812 06:17:37.461403 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac): perf score=14.095187
I20260812 06:17:37.521975 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.060s	user 0.040s	sys 0.011s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24428,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:37.522543 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac): perf score=2.188937
I20260812 06:17:37.532394 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3542,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:37.533041 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling MajorDeltaCompactionOp(787ecaa338d349a6a241ec85a9837eac): perf score=1.000000
I20260812 06:17:37.695828 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: MajorDeltaCompactionOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.163s	user 0.109s	sys 0.053s 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":479,"lbm_read_time_us":12207,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29140,"lbm_writes_lt_1ms":543,"mutex_wait_us":271,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11776,"update_count":2500}
I20260812 06:17:37.696367 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac): perf score=14.095187
I20260812 06:17:37.741576 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.045s	user 0.033s	sys 0.011s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":19914,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:37.742134 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac): perf score=2.188937
I20260812 06:17:37.753829 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4381,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:37.754333 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling MajorDeltaCompactionOp(787ecaa338d349a6a241ec85a9837eac): perf score=1.000000
I20260812 06:17:37.920926 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: MajorDeltaCompactionOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.166s	user 0.102s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815681,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":721,"lbm_read_time_us":14607,"lbm_reads_lt_1ms":572,"lbm_write_time_us":24788,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10368,"update_count":2500}
I20260812 06:17:37.921389 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac): perf score=14.095187
I20260812 06:17:37.972540 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.051s	user 0.033s	sys 0.015s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19012,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:37.973162 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac): perf score=2.188937
I20260812 06:17:37.983974 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4136,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:37.984537 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling FlushMRSOp(787ecaa338d349a6a241ec85a9837eac): perf score=1.000000
I20260812 06:17:38.021621 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: FlushMRSOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.037s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1193507,"cfile_init":1,"dirs.queue_time_us":41,"dirs.run_cpu_time_us":183,"dirs.run_wall_time_us":1237,"drs_written":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1665,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:38.022341 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling LogGCOp(787ecaa338d349a6a241ec85a9837eac): free 115943179 bytes of WAL
I20260812 06:17:38.022579 22760 log_reader.cc:385] T 787ecaa338d349a6a241ec85a9837eac: removed 11 log segments from log reader
I20260812 06:17:38.022631 22760 log.cc:1079] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/787ecaa338d349a6a241ec85a9837eac/wal-000000016 (ops 75-79)
I20260812 06:17:38.022670 22760 log.cc:1079] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/787ecaa338d349a6a241ec85a9837eac/wal-000000017 (ops 80-84)
I20260812 06:17:38.022711 22760 log.cc:1079] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/787ecaa338d349a6a241ec85a9837eac/wal-000000018 (ops 85-89)
I20260812 06:17:38.022743 22760 log.cc:1079] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/787ecaa338d349a6a241ec85a9837eac/wal-000000019 (ops 90-94)
I20260812 06:17:38.022773 22760 log.cc:1079] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/787ecaa338d349a6a241ec85a9837eac/wal-000000020 (ops 95-99)
I20260812 06:17:38.022804 22760 log.cc:1079] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/787ecaa338d349a6a241ec85a9837eac/wal-000000021 (ops 100-104)
I20260812 06:17:38.022833 22760 log.cc:1079] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/787ecaa338d349a6a241ec85a9837eac/wal-000000022 (ops 105-109)
I20260812 06:17:38.022862 22760 log.cc:1079] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/787ecaa338d349a6a241ec85a9837eac/wal-000000023 (ops 110-114)
I20260812 06:17:38.022892 22760 log.cc:1079] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/787ecaa338d349a6a241ec85a9837eac/wal-000000024 (ops 115-119)
I20260812 06:17:38.022921 22760 log.cc:1079] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/787ecaa338d349a6a241ec85a9837eac/wal-000000025 (ops 120-124)
I20260812 06:17:38.022951 22760 log.cc:1079] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/787ecaa338d349a6a241ec85a9837eac/wal-000000026 (ops 125-129)
I20260812 06:17:38.042749 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: LogGCOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.020s	user 0.000s	sys 0.018s Metrics: {}
I20260812 06:17:38.043334 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling UndoDeltaBlockGCOp(787ecaa338d349a6a241ec85a9837eac): 462 bytes on disk
I20260812 06:17:38.043810 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: UndoDeltaBlockGCOp(787ecaa338d349a6a241ec85a9837eac) 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:17:38.044389 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac): perf score=2.188937
I20260812 06:17:38.062327 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.018s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4734,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:38.062692 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac): perf score=2.188937
I20260812 06:17:38.072203 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.009s	user 0.001s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3661,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:38.072569 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling MajorDeltaCompactionOp(787ecaa338d349a6a241ec85a9837eac): perf score=1.000000
I20260812 06:17:38.278020 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: MajorDeltaCompactionOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.205s	user 0.138s	sys 0.061s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020745,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":2042,"lbm_read_time_us":13815,"lbm_reads_lt_1ms":774,"lbm_write_time_us":34828,"lbm_writes_lt_1ms":743,"mutex_wait_us":39,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":14464,"thread_start_us":63,"threads_started":1,"update_count":3500}
I20260812 06:17:38.278544 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac): perf score=18.063937
I20260812 06:17:38.342935 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.064s	user 0.047s	sys 0.016s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":31712,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":500,"reinsert_count":0,"update_count":2500}
I20260812 06:17:38.343462 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac): perf score=2.188937
I20260812 06:17:38.363305 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.020s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5627,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:38.363734 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac): perf score=2.188937
I20260812 06:17:38.373250 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.009s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3729,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:38.373736 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling MajorDeltaCompactionOp(787ecaa338d349a6a241ec85a9837eac): perf score=1.000000
I20260812 06:17:38.545359 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: MajorDeltaCompactionOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.171s	user 0.134s	sys 0.036s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":33020628,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1080,"lbm_read_time_us":12210,"lbm_reads_lt_1ms":773,"lbm_write_time_us":34969,"lbm_writes_lt_1ms":743,"mutex_wait_us":389,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":8960,"update_count":3500}
I20260812 06:17:38.545993 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac): perf score=15.087375
I20260812 06:17:38.587255 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.041s	user 0.024s	sys 0.012s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":16279,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:17:38.587754 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac): perf score=2.188937
I20260812 06:17:38.611984 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.024s	user 0.001s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4465,"lbm_writes_lt_1ms":93,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":450}
I20260812 06:17:38.612476 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac): perf score=2.188937
I20260812 06:17:38.622479 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3812,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:38.623062 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling MajorDeltaCompactionOp(787ecaa338d349a6a241ec85a9837eac): perf score=1.000000
I20260812 06:17:38.797212 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: MajorDeltaCompactionOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.174s	user 0.132s	sys 0.041s 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":714,"lbm_read_time_us":14398,"lbm_reads_lt_1ms":673,"lbm_write_time_us":36727,"lbm_writes_lt_1ms":643,"mutex_wait_us":34,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":3000}
I20260812 06:17:38.797737 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac): perf score=14.095187
I20260812 06:17:38.841893 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.044s	user 0.027s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":17588,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:38.842355 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac): perf score=2.188937
I20260812 06:17:38.854244 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.012s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4569,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:38.854799 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling MajorDeltaCompactionOp(787ecaa338d349a6a241ec85a9837eac): perf score=1.000000
I20260812 06:17:39.011686 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: MajorDeltaCompactionOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.157s	user 0.106s	sys 0.040s 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":189,"lbm_read_time_us":10089,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28651,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":58112,"update_count":2500}
I20260812 06:17:39.012297 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac): perf score=14.095187
I20260812 06:17:39.047677 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.035s	user 0.016s	sys 0.017s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":15593,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:39.048120 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling MajorDeltaCompactionOp(787ecaa338d349a6a241ec85a9837eac): perf score=1.000000
I20260812 06:17:39.197131 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: MajorDeltaCompactionOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.149s	user 0.102s	sys 0.036s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713154,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":604,"lbm_read_time_us":10054,"lbm_reads_lt_1ms":467,"lbm_write_time_us":21868,"lbm_writes_lt_1ms":443,"mutex_wait_us":286,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5632,"update_count":2000}
I20260812 06:17:39.197785 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac): perf score=14.095187
I20260812 06:17:39.250025 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.052s	user 0.019s	sys 0.032s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22387,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:39.250644 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac): perf score=2.188937
I20260812 06:17:39.262387 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4354,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:39.262882 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling FlushMRSOp(787ecaa338d349a6a241ec85a9837eac): perf score=1.000000
I20260812 06:17:39.293790 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: FlushMRSOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.031s	user 0.025s	sys 0.004s Metrics: {"bytes_written":1193507,"cfile_init":1,"dirs.queue_time_us":52,"dirs.run_cpu_time_us":297,"dirs.run_wall_time_us":1303,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1353,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:39.294535 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling LogGCOp(787ecaa338d349a6a241ec85a9837eac): free 120553638 bytes of WAL
I20260812 06:17:39.294785 22760 log_reader.cc:385] T 787ecaa338d349a6a241ec85a9837eac: removed 12 log segments from log reader
I20260812 06:17:39.294835 22760 log.cc:1079] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/787ecaa338d349a6a241ec85a9837eac/wal-000000027 (ops 130-134)
I20260812 06:17:39.294872 22760 log.cc:1079] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/787ecaa338d349a6a241ec85a9837eac/wal-000000028 (ops 135-139)
I20260812 06:17:39.294904 22760 log.cc:1079] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/787ecaa338d349a6a241ec85a9837eac/wal-000000029 (ops 140-144)
I20260812 06:17:39.294934 22760 log.cc:1079] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/787ecaa338d349a6a241ec85a9837eac/wal-000000030 (ops 145-149)
I20260812 06:17:39.294965 22760 log.cc:1079] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/787ecaa338d349a6a241ec85a9837eac/wal-000000031 (ops 150-154)
I20260812 06:17:39.294994 22760 log.cc:1079] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/787ecaa338d349a6a241ec85a9837eac/wal-000000032 (ops 155-159)
I20260812 06:17:39.295023 22760 log.cc:1079] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/787ecaa338d349a6a241ec85a9837eac/wal-000000033 (ops 160-164)
I20260812 06:17:39.295053 22760 log.cc:1079] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/787ecaa338d349a6a241ec85a9837eac/wal-000000034 (ops 165-168)
I20260812 06:17:39.295083 22760 log.cc:1079] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/787ecaa338d349a6a241ec85a9837eac/wal-000000035 (ops 169-173)
I20260812 06:17:39.295113 22760 log.cc:1079] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/787ecaa338d349a6a241ec85a9837eac/wal-000000036 (ops 174-178)
I20260812 06:17:39.295142 22760 log.cc:1079] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/787ecaa338d349a6a241ec85a9837eac/wal-000000037 (ops 179-182)
I20260812 06:17:39.295171 22760 log.cc:1079] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/787ecaa338d349a6a241ec85a9837eac/wal-000000038 (ops 183-187)
I20260812 06:17:39.316866 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: LogGCOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.022s	user 0.000s	sys 0.018s Metrics: {}
I20260812 06:17:39.317337 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling UndoDeltaBlockGCOp(787ecaa338d349a6a241ec85a9837eac): 462 bytes on disk
I20260812 06:17:39.317770 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: UndoDeltaBlockGCOp(787ecaa338d349a6a241ec85a9837eac) 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:17:39.318431 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac): perf score=3.181125
I20260812 06:17:39.335094 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.016s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":3902,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:39.335523 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling LogGCOp(787ecaa338d349a6a241ec85a9837eac): free 12017952 bytes of WAL
I20260812 06:17:39.335714 22760 log_reader.cc:385] T 787ecaa338d349a6a241ec85a9837eac: removed 1 log segments from log reader
I20260812 06:17:39.335758 22760 log.cc:1079] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990: Deleting log segment in path: /tmp/dist-test-tasko3hsL_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515450110720-22222-0/minicluster-data/ts-0-root/wals/787ecaa338d349a6a241ec85a9837eac/wal-000000039 (ops 188-192)
I20260812 06:17:39.337677 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: LogGCOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.002s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:17:39.337957 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac): perf score=2.188937
I20260812 06:17:39.347158 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.009s	user 0.001s	sys 0.006s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3192,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:39.347754 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling MajorDeltaCompactionOp(787ecaa338d349a6a241ec85a9837eac): perf score=1.000000
I20260812 06:17:39.517896 22222 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.295s	user 1.567s	sys 0.152s
I20260812 06:17:39.558677 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: MajorDeltaCompactionOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.211s	user 0.144s	sys 0.065s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020734,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":15687,"lbm_reads_lt_1ms":770,"lbm_write_time_us":37767,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":3500}
I20260812 06:17:39.559152 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac): perf score=14.095187
I20260812 06:17:39.589066 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: FlushDeltaMemStoresOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.030s	user 0.028s	sys 0.001s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":13840,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:39.589520 22889 maintenance_manager.cc:419] P 45469f189fce4cff9e0cd7c01435d990: Scheduling MajorDeltaCompactionOp(787ecaa338d349a6a241ec85a9837eac): perf score=1.000000
I20260812 06:17:39.610312 22222 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.092s	user 0.003s	sys 0.000s
I20260812 06:17:39.610847 22222 tablet_server.cc:179] TabletServer@127.21.179.129:0 shutting down...
I20260812 06:17:39.706825 22760 maintenance_manager.cc:643] P 45469f189fce4cff9e0cd7c01435d990: MajorDeltaCompactionOp(787ecaa338d349a6a241ec85a9837eac) complete. Timing: real 0.117s	user 0.074s	sys 0.043s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713151,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":835,"lbm_read_time_us":8751,"lbm_reads_lt_1ms":467,"lbm_write_time_us":19833,"lbm_writes_lt_1ms":443,"mutex_wait_us":319,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6016,"update_count":2000}
I20260812 06:17:39.707350 22222 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:39.707590 22222 tablet_replica.cc:333] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990: stopping tablet replica
I20260812 06:17:39.707705 22222 raft_consensus.cc:2243] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:39.707870 22222 raft_consensus.cc:2272] T 787ecaa338d349a6a241ec85a9837eac P 45469f189fce4cff9e0cd7c01435d990 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:39.712419 22222 tablet_server.cc:196] TabletServer@127.21.179.129:0 shutdown complete.
I20260812 06:17:39.744712 22222 master.cc:562] Master@127.21.179.190:43063 shutting down...
I20260812 06:17:39.747711 22222 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 609b4caac8af45b2a4522f3899de40ff [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:39.747874 22222 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 609b4caac8af45b2a4522f3899de40ff [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:39.747946 22222 tablet_replica.cc:333] T 00000000000000000000000000000000 P 609b4caac8af45b2a4522f3899de40ff: stopping tablet replica
I20260812 06:17:39.759943 22222 master.cc:584] Master@127.21.179.190:43063 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (4787 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (9711 ms total)

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