[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:19:12.852401 28838 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.28.41.190:36423
I20260812 06:19:12.853505 28838 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:19:12.854141 28838 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:12.860544 28855 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:12.860545 28854 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:12.860847 28858 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:12.860908 28838 server_base.cc:1061] running on GCE node
I20260812 06:19:12.861361 28838 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:12.861487 28838 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:12.861558 28838 hybrid_clock.cc:648] HybridClock initialized: now 1786515552861556 us; error 0 us; skew 500 ppm
I20260812 06:19:12.863405 28838 webserver.cc:533] Webserver started at http://127.28.41.190:45041/ using document root <none> and password file <none>
I20260812 06:19:12.863960 28838 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:12.864054 28838 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:12.864362 28838 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:12.866730 28838 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552841366-28838-0/minicluster-data/master-0-root/instance:
uuid: "b29f20866cd047ae967eded06a04dee9"
format_stamp: "Formatted at 2026-08-12 06:19:12 on dist-test-slave-g170"
I20260812 06:19:12.870805 28838 fs_manager.cc:696] Time spent creating directory manager: real 0.004s	user 0.005s	sys 0.000s
I20260812 06:19:12.873277 28863 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:12.874385 28838 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:19:12.874532 28838 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552841366-28838-0/minicluster-data/master-0-root
uuid: "b29f20866cd047ae967eded06a04dee9"
format_stamp: "Formatted at 2026-08-12 06:19:12 on dist-test-slave-g170"
I20260812 06:19:12.874644 28838 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552841366-28838-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552841366-28838-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552841366-28838-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:12.893186 28838 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:12.893839 28838 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:19:12.894029 28838 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:12.902469 28838 rpc_server.cc:307] RPC server started. Bound to: 127.28.41.190:36423
I20260812 06:19:12.902477 28961 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.28.41.190:36423 every 8 connection(s)
I20260812 06:19:12.904675 28962 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:12.909968 28962 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P b29f20866cd047ae967eded06a04dee9: Bootstrap starting.
I20260812 06:19:12.912199 28962 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P b29f20866cd047ae967eded06a04dee9: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:12.913057 28962 log.cc:826] T 00000000000000000000000000000000 P b29f20866cd047ae967eded06a04dee9: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:12.914644 28962 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P b29f20866cd047ae967eded06a04dee9: No bootstrap required, opened a new log
I20260812 06:19:12.917332 28962 raft_consensus.cc:359] T 00000000000000000000000000000000 P b29f20866cd047ae967eded06a04dee9 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b29f20866cd047ae967eded06a04dee9" member_type: VOTER }
I20260812 06:19:12.917485 28962 raft_consensus.cc:385] T 00000000000000000000000000000000 P b29f20866cd047ae967eded06a04dee9 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:12.917552 28962 raft_consensus.cc:740] T 00000000000000000000000000000000 P b29f20866cd047ae967eded06a04dee9 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: b29f20866cd047ae967eded06a04dee9, State: Initialized, Role: FOLLOWER
I20260812 06:19:12.918104 28962 consensus_queue.cc:260] T 00000000000000000000000000000000 P b29f20866cd047ae967eded06a04dee9 [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: "b29f20866cd047ae967eded06a04dee9" member_type: VOTER }
I20260812 06:19:12.918268 28962 raft_consensus.cc:399] T 00000000000000000000000000000000 P b29f20866cd047ae967eded06a04dee9 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:12.918350 28962 raft_consensus.cc:493] T 00000000000000000000000000000000 P b29f20866cd047ae967eded06a04dee9 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:12.918509 28962 raft_consensus.cc:3060] T 00000000000000000000000000000000 P b29f20866cd047ae967eded06a04dee9 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:12.919245 28962 raft_consensus.cc:515] T 00000000000000000000000000000000 P b29f20866cd047ae967eded06a04dee9 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b29f20866cd047ae967eded06a04dee9" member_type: VOTER }
I20260812 06:19:12.919656 28962 leader_election.cc:304] T 00000000000000000000000000000000 P b29f20866cd047ae967eded06a04dee9 [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: b29f20866cd047ae967eded06a04dee9; no voters: 
I20260812 06:19:12.919961 28962 leader_election.cc:290] T 00000000000000000000000000000000 P b29f20866cd047ae967eded06a04dee9 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:12.920125 28965 raft_consensus.cc:2804] T 00000000000000000000000000000000 P b29f20866cd047ae967eded06a04dee9 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:12.920396 28965 raft_consensus.cc:697] T 00000000000000000000000000000000 P b29f20866cd047ae967eded06a04dee9 [term 1 LEADER]: Becoming Leader. State: Replica: b29f20866cd047ae967eded06a04dee9, State: Running, Role: LEADER
I20260812 06:19:12.920807 28965 consensus_queue.cc:237] T 00000000000000000000000000000000 P b29f20866cd047ae967eded06a04dee9 [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: "b29f20866cd047ae967eded06a04dee9" member_type: VOTER }
I20260812 06:19:12.920965 28962 sys_catalog.cc:565] T 00000000000000000000000000000000 P b29f20866cd047ae967eded06a04dee9 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:12.922537 28967 sys_catalog.cc:455] T 00000000000000000000000000000000 P b29f20866cd047ae967eded06a04dee9 [sys.catalog]: SysCatalogTable state changed. Reason: New leader b29f20866cd047ae967eded06a04dee9. Latest consensus state: current_term: 1 leader_uuid: "b29f20866cd047ae967eded06a04dee9" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b29f20866cd047ae967eded06a04dee9" member_type: VOTER } }
I20260812 06:19:12.922590 28966 sys_catalog.cc:455] T 00000000000000000000000000000000 P b29f20866cd047ae967eded06a04dee9 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "b29f20866cd047ae967eded06a04dee9" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b29f20866cd047ae967eded06a04dee9" member_type: VOTER } }
I20260812 06:19:12.922654 28967 sys_catalog.cc:458] T 00000000000000000000000000000000 P b29f20866cd047ae967eded06a04dee9 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:12.922708 28966 sys_catalog.cc:458] T 00000000000000000000000000000000 P b29f20866cd047ae967eded06a04dee9 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:12.923147 28990 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:12.923380 28838 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:12.925444 28990 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:12.929589 28990 catalog_manager.cc:1383] Generated new cluster ID: e230aa8586ce4e8ebf43a6f82571c6b2
I20260812 06:19:12.929647 28990 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:12.953563 28990 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:12.954775 28990 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:12.966230 28990 catalog_manager.cc:6092] T 00000000000000000000000000000000 P b29f20866cd047ae967eded06a04dee9: Generated new TSK 0
I20260812 06:19:12.967032 28990 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:12.988689 28838 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:12.991741 29011 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:12.991829 29006 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:12.991780 29005 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:12.992517 28838 server_base.cc:1061] running on GCE node
I20260812 06:19:12.992817 28838 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:12.992877 28838 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:12.992919 28838 hybrid_clock.cc:648] HybridClock initialized: now 1786515552992918 us; error 0 us; skew 500 ppm
I20260812 06:19:12.993933 28838 webserver.cc:533] Webserver started at http://127.28.41.129:44385/ using document root <none> and password file <none>
I20260812 06:19:12.994134 28838 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:12.994190 28838 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:12.994297 28838 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:12.994742 28838 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552841366-28838-0/minicluster-data/ts-0-root/instance:
uuid: "25c00dac6a354ecd93c53d8e2630db55"
format_stamp: "Formatted at 2026-08-12 06:19:12 on dist-test-slave-g170"
I20260812 06:19:12.996490 28838 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.001s
I20260812 06:19:12.997669 29018 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:12.997967 28838 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:12.998044 28838 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552841366-28838-0/minicluster-data/ts-0-root
uuid: "25c00dac6a354ecd93c53d8e2630db55"
format_stamp: "Formatted at 2026-08-12 06:19:12 on dist-test-slave-g170"
I20260812 06:19:12.998144 28838 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552841366-28838-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552841366-28838-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552841366-28838-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:13.025143 28838 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:13.025673 28838 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:13.026275 28838 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:13.027235 28838 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:13.027292 28838 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:13.027369 28838 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:13.027416 28838 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:13.034991 28838 rpc_server.cc:307] RPC server started. Bound to: 127.28.41.129:40749
I20260812 06:19:13.035435 29140 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.28.41.129:40749 every 8 connection(s)
I20260812 06:19:13.045229 29141 heartbeater.cc:344] Connected to a master server at 127.28.41.190:36423
I20260812 06:19:13.045506 29141 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:13.046005 29141 heartbeater.cc:507] Master 127.28.41.190:36423 requested a full tablet report, sending...
I20260812 06:19:13.047569 28889 ts_manager.cc:194] Registered new tserver with Master: 25c00dac6a354ecd93c53d8e2630db55 (127.28.41.129:40749)
I20260812 06:19:13.048424 28838 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012407524s
I20260812 06:19:13.048950 28889 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:36648
I20260812 06:19:13.058038 28889 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:36664:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:13.075522 29077 tablet_service.cc:1511] Processing CreateTablet for tablet f30fbc36ff2142b48cc3b3041a4df84d (DEFAULT_TABLE table=heavy-update-compaction-test [id=d1144bdf6acd421d9d19c79f688c455c]), partition=
I20260812 06:19:13.076138 29077 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet f30fbc36ff2142b48cc3b3041a4df84d. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:13.080224 29169 tablet_bootstrap.cc:492] T f30fbc36ff2142b48cc3b3041a4df84d P 25c00dac6a354ecd93c53d8e2630db55: Bootstrap starting.
I20260812 06:19:13.081936 29169 tablet_bootstrap.cc:654] T f30fbc36ff2142b48cc3b3041a4df84d P 25c00dac6a354ecd93c53d8e2630db55: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:13.083290 29169 tablet_bootstrap.cc:492] T f30fbc36ff2142b48cc3b3041a4df84d P 25c00dac6a354ecd93c53d8e2630db55: No bootstrap required, opened a new log
I20260812 06:19:13.083396 29169 ts_tablet_manager.cc:1403] T f30fbc36ff2142b48cc3b3041a4df84d P 25c00dac6a354ecd93c53d8e2630db55: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:19:13.083959 29169 raft_consensus.cc:359] T f30fbc36ff2142b48cc3b3041a4df84d P 25c00dac6a354ecd93c53d8e2630db55 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "25c00dac6a354ecd93c53d8e2630db55" member_type: VOTER last_known_addr { host: "127.28.41.129" port: 40749 } }
I20260812 06:19:13.084060 29169 raft_consensus.cc:385] T f30fbc36ff2142b48cc3b3041a4df84d P 25c00dac6a354ecd93c53d8e2630db55 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:13.084084 29169 raft_consensus.cc:740] T f30fbc36ff2142b48cc3b3041a4df84d P 25c00dac6a354ecd93c53d8e2630db55 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 25c00dac6a354ecd93c53d8e2630db55, State: Initialized, Role: FOLLOWER
I20260812 06:19:13.084232 29169 consensus_queue.cc:260] T f30fbc36ff2142b48cc3b3041a4df84d P 25c00dac6a354ecd93c53d8e2630db55 [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: "25c00dac6a354ecd93c53d8e2630db55" member_type: VOTER last_known_addr { host: "127.28.41.129" port: 40749 } }
I20260812 06:19:13.084321 29169 raft_consensus.cc:399] T f30fbc36ff2142b48cc3b3041a4df84d P 25c00dac6a354ecd93c53d8e2630db55 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:13.084352 29169 raft_consensus.cc:493] T f30fbc36ff2142b48cc3b3041a4df84d P 25c00dac6a354ecd93c53d8e2630db55 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:13.084419 29169 raft_consensus.cc:3060] T f30fbc36ff2142b48cc3b3041a4df84d P 25c00dac6a354ecd93c53d8e2630db55 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:13.085350 29169 raft_consensus.cc:515] T f30fbc36ff2142b48cc3b3041a4df84d P 25c00dac6a354ecd93c53d8e2630db55 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "25c00dac6a354ecd93c53d8e2630db55" member_type: VOTER last_known_addr { host: "127.28.41.129" port: 40749 } }
I20260812 06:19:13.085469 29169 leader_election.cc:304] T f30fbc36ff2142b48cc3b3041a4df84d P 25c00dac6a354ecd93c53d8e2630db55 [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: 25c00dac6a354ecd93c53d8e2630db55; no voters: 
I20260812 06:19:13.085620 29169 leader_election.cc:290] T f30fbc36ff2142b48cc3b3041a4df84d P 25c00dac6a354ecd93c53d8e2630db55 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:13.085783 29171 raft_consensus.cc:2804] T f30fbc36ff2142b48cc3b3041a4df84d P 25c00dac6a354ecd93c53d8e2630db55 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:13.086019 29169 ts_tablet_manager.cc:1434] T f30fbc36ff2142b48cc3b3041a4df84d P 25c00dac6a354ecd93c53d8e2630db55: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:19:13.086025 29171 raft_consensus.cc:697] T f30fbc36ff2142b48cc3b3041a4df84d P 25c00dac6a354ecd93c53d8e2630db55 [term 1 LEADER]: Becoming Leader. State: Replica: 25c00dac6a354ecd93c53d8e2630db55, State: Running, Role: LEADER
I20260812 06:19:13.086251 29171 consensus_queue.cc:237] T f30fbc36ff2142b48cc3b3041a4df84d P 25c00dac6a354ecd93c53d8e2630db55 [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: "25c00dac6a354ecd93c53d8e2630db55" member_type: VOTER last_known_addr { host: "127.28.41.129" port: 40749 } }
I20260812 06:19:13.086277 29141 heartbeater.cc:499] Master 127.28.41.190:36423 was elected leader, sending a full tablet report...
I20260812 06:19:13.089005 28889 catalog_manager.cc:5719] T f30fbc36ff2142b48cc3b3041a4df84d P 25c00dac6a354ecd93c53d8e2630db55 reported cstate change: term changed from 0 to 1, leader changed from <none> to 25c00dac6a354ecd93c53d8e2630db55 (127.28.41.129). New cstate: current_term: 1 leader_uuid: "25c00dac6a354ecd93c53d8e2630db55" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "25c00dac6a354ecd93c53d8e2630db55" member_type: VOTER last_known_addr { host: "127.28.41.129" port: 40749 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:13.151647 28838 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.054s	user 0.012s	sys 0.012s
I20260812 06:19:13.286621 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling FlushMRSOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=16.078378
I20260812 06:19:13.454792 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: FlushMRSOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.168s	user 0.136s	sys 0.028s Metrics: {"bytes_written":9148636,"cfile_init":1,"compiler_manager_pool.queue_time_us":455,"delete_count":0,"dirs.queue_time_us":70,"dirs.run_cpu_time_us":231,"dirs.run_wall_time_us":838,"drs_written":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40400,"lbm_writes_lt_1ms":680,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":161024,"thread_start_us":145,"threads_started":1,"update_count":1115}
I20260812 06:19:13.455976 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling LogGCOp(f30fbc36ff2142b48cc3b3041a4df84d): free 20743880 bytes of WAL
I20260812 06:19:13.456312 29027 log_reader.cc:385] T f30fbc36ff2142b48cc3b3041a4df84d: removed 2 log segments from log reader
I20260812 06:19:13.456393 29027 log.cc:1079] T f30fbc36ff2142b48cc3b3041a4df84d P 25c00dac6a354ecd93c53d8e2630db55: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/f30fbc36ff2142b48cc3b3041a4df84d/wal-000000001 (ops 1-6)
I20260812 06:19:13.456502 29027 log.cc:1079] T f30fbc36ff2142b48cc3b3041a4df84d P 25c00dac6a354ecd93c53d8e2630db55: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/f30fbc36ff2142b48cc3b3041a4df84d/wal-000000002 (ops 7-11)
I20260812 06:19:13.462970 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: LogGCOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.007s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:19:13.463395 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=1.196750
I20260812 06:19:13.474938 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":3159080,"delete_count":0,"lbm_write_time_us":4127,"lbm_writes_lt_1ms":80,"reinsert_count":0,"update_count":385}
I20260812 06:19:13.475494 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling MajorDeltaCompactionOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=1.000000
I20260812 06:19:13.590252 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: MajorDeltaCompactionOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.115s	user 0.097s	sys 0.012s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16569844,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":495,"lbm_read_time_us":6969,"lbm_reads_lt_1ms":364,"lbm_write_time_us":19856,"lbm_writes_lt_1ms":343,"mutex_wait_us":25,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":149760,"thread_start_us":316,"threads_started":5,"update_count":1500}
I20260812 06:19:13.590919 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling UndoDeltaBlockGCOp(f30fbc36ff2142b48cc3b3041a4df84d): 16411398 bytes on disk
I20260812 06:19:13.591575 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: UndoDeltaBlockGCOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":91,"lbm_reads_lt_1ms":4}
I20260812 06:19:13.592110 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=10.126437
I20260812 06:19:13.637070 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.045s	user 0.026s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14940,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":9472,"update_count":1500}
I20260812 06:19:13.637581 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=2.188937
I20260812 06:19:13.647977 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3994,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:13.648422 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling MajorDeltaCompactionOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=1.000000
I20260812 06:19:13.786541 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: MajorDeltaCompactionOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.138s	user 0.109s	sys 0.026s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":595,"lbm_read_time_us":10521,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26844,"lbm_writes_lt_1ms":443,"mutex_wait_us":340,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:19:13.787250 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=10.126437
I20260812 06:19:13.840725 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.053s	user 0.012s	sys 0.032s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":18375,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:13.841329 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=2.188937
I20260812 06:19:13.852356 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4282,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:13.852850 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling MajorDeltaCompactionOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=1.000000
I20260812 06:19:14.005404 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: MajorDeltaCompactionOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.152s	user 0.120s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":197,"lbm_read_time_us":11203,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26322,"lbm_writes_lt_1ms":443,"mutex_wait_us":35,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16128,"update_count":2000}
I20260812 06:19:14.006161 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=10.126437
I20260812 06:19:14.055356 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.049s	user 0.022s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":22210,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:14.055909 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=2.188937
I20260812 06:19:14.069787 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.014s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5271,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:14.070319 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling MajorDeltaCompactionOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=1.000000
I20260812 06:19:14.211004 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: MajorDeltaCompactionOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.141s	user 0.094s	sys 0.035s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":711,"lbm_read_time_us":10270,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26569,"lbm_writes_lt_1ms":443,"mutex_wait_us":365,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12288,"update_count":2000}
I20260812 06:19:14.211629 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=14.095187
I20260812 06:19:14.264338 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.053s	user 0.035s	sys 0.013s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23427,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:14.264947 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=2.188937
I20260812 06:19:14.280310 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5845,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:14.280974 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling MajorDeltaCompactionOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=1.000000
I20260812 06:19:14.435428 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: MajorDeltaCompactionOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.154s	user 0.137s	sys 0.016s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":724,"lbm_read_time_us":12519,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32934,"lbm_writes_lt_1ms":543,"mutex_wait_us":350,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8576,"update_count":2500}
I20260812 06:19:14.436261 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=10.126437
I20260812 06:19:14.470979 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.034s	user 0.028s	sys 0.004s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14860,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:14.471481 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=2.188937
I20260812 06:19:14.487850 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.016s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5676,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:14.488426 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling MajorDeltaCompactionOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=1.000000
I20260812 06:19:14.613996 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: MajorDeltaCompactionOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.125s	user 0.080s	sys 0.043s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":326,"lbm_read_time_us":8718,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26985,"lbm_writes_lt_1ms":443,"mutex_wait_us":66,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9856,"update_count":2000}
I20260812 06:19:14.614538 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=11.118625
I20260812 06:19:14.654175 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.039s	user 0.011s	sys 0.027s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":13946,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:14.654819 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=2.188937
I20260812 06:19:14.668928 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.014s	user 0.010s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5537,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:14.669378 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling FlushMRSOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=1.000000
I20260812 06:19:14.698102 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: FlushMRSOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.029s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":81,"dirs.run_cpu_time_us":230,"dirs.run_wall_time_us":1333,"drs_written":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1934,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:14.699137 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling LogGCOp(f30fbc36ff2142b48cc3b3041a4df84d): free 112239262 bytes of WAL
I20260812 06:19:14.699410 29027 log_reader.cc:385] T f30fbc36ff2142b48cc3b3041a4df84d: removed 11 log segments from log reader
I20260812 06:19:14.699488 29027 log.cc:1079] T f30fbc36ff2142b48cc3b3041a4df84d P 25c00dac6a354ecd93c53d8e2630db55: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/f30fbc36ff2142b48cc3b3041a4df84d/wal-000000003 (ops 12-16)
I20260812 06:19:14.699553 29027 log.cc:1079] T f30fbc36ff2142b48cc3b3041a4df84d P 25c00dac6a354ecd93c53d8e2630db55: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/f30fbc36ff2142b48cc3b3041a4df84d/wal-000000004 (ops 17-21)
I20260812 06:19:14.699611 29027 log.cc:1079] T f30fbc36ff2142b48cc3b3041a4df84d P 25c00dac6a354ecd93c53d8e2630db55: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/f30fbc36ff2142b48cc3b3041a4df84d/wal-000000005 (ops 22-26)
I20260812 06:19:14.699659 29027 log.cc:1079] T f30fbc36ff2142b48cc3b3041a4df84d P 25c00dac6a354ecd93c53d8e2630db55: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/f30fbc36ff2142b48cc3b3041a4df84d/wal-000000006 (ops 27-31)
I20260812 06:19:14.699702 29027 log.cc:1079] T f30fbc36ff2142b48cc3b3041a4df84d P 25c00dac6a354ecd93c53d8e2630db55: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/f30fbc36ff2142b48cc3b3041a4df84d/wal-000000007 (ops 32-36)
I20260812 06:19:14.699743 29027 log.cc:1079] T f30fbc36ff2142b48cc3b3041a4df84d P 25c00dac6a354ecd93c53d8e2630db55: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/f30fbc36ff2142b48cc3b3041a4df84d/wal-000000008 (ops 37-41)
I20260812 06:19:14.699783 29027 log.cc:1079] T f30fbc36ff2142b48cc3b3041a4df84d P 25c00dac6a354ecd93c53d8e2630db55: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/f30fbc36ff2142b48cc3b3041a4df84d/wal-000000009 (ops 42-46)
I20260812 06:19:14.699823 29027 log.cc:1079] T f30fbc36ff2142b48cc3b3041a4df84d P 25c00dac6a354ecd93c53d8e2630db55: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/f30fbc36ff2142b48cc3b3041a4df84d/wal-000000010 (ops 47-50)
I20260812 06:19:14.699863 29027 log.cc:1079] T f30fbc36ff2142b48cc3b3041a4df84d P 25c00dac6a354ecd93c53d8e2630db55: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/f30fbc36ff2142b48cc3b3041a4df84d/wal-000000011 (ops 51-55)
I20260812 06:19:14.699905 29027 log.cc:1079] T f30fbc36ff2142b48cc3b3041a4df84d P 25c00dac6a354ecd93c53d8e2630db55: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/f30fbc36ff2142b48cc3b3041a4df84d/wal-000000012 (ops 56-60)
I20260812 06:19:14.699945 29027 log.cc:1079] T f30fbc36ff2142b48cc3b3041a4df84d P 25c00dac6a354ecd93c53d8e2630db55: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/f30fbc36ff2142b48cc3b3041a4df84d/wal-000000013 (ops 61-65)
I20260812 06:19:14.731855 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: LogGCOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.032s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:19:14.732470 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=3.181125
I20260812 06:19:14.754793 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.022s	user 0.020s	sys 0.000s Metrics: {"bytes_written":4759047,"delete_count":0,"lbm_write_time_us":8458,"lbm_writes_lt_1ms":119,"reinsert_count":0,"update_count":580}
I20260812 06:19:14.755306 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling UndoDeltaBlockGCOp(f30fbc36ff2142b48cc3b3041a4df84d): 462 bytes on disk
I20260812 06:19:14.755766 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: UndoDeltaBlockGCOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4}
I20260812 06:19:14.756286 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=2.188937
I20260812 06:19:14.766425 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3446255,"delete_count":0,"lbm_write_time_us":3738,"lbm_writes_lt_1ms":87,"reinsert_count":0,"update_count":420}
I20260812 06:19:14.767120 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling MajorDeltaCompactionOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=1.000000
I20260812 06:19:14.977237 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: MajorDeltaCompactionOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.210s	user 0.132s	sys 0.077s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877315,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":712,"lbm_read_time_us":17273,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34909,"lbm_writes_lt_1ms":643,"mutex_wait_us":23,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":23168,"thread_start_us":81,"threads_started":1,"update_count":3000}
I20260812 06:19:14.978013 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=14.095187
I20260812 06:19:15.028988 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.051s	user 0.013s	sys 0.037s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":23888,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:15.029477 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=2.188937
I20260812 06:19:15.039903 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4118,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:15.040354 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling MajorDeltaCompactionOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=1.000000
I20260812 06:19:15.224370 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: MajorDeltaCompactionOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.184s	user 0.104s	sys 0.068s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":838,"lbm_read_time_us":13814,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32295,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2500}
I20260812 06:19:15.224906 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=14.095187
I20260812 06:19:15.282145 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.057s	user 0.019s	sys 0.032s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":20609,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:15.282600 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=2.188937
I20260812 06:19:15.293409 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4239,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:15.294014 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling MajorDeltaCompactionOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=1.000000
I20260812 06:19:15.483533 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: MajorDeltaCompactionOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.189s	user 0.145s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":751,"lbm_read_time_us":13084,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34810,"lbm_writes_lt_1ms":543,"mutex_wait_us":62,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:19:15.484293 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=10.126437
I20260812 06:19:15.532040 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.048s	user 0.023s	sys 0.019s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":20238,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:15.532584 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=2.188937
I20260812 06:19:15.553694 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.021s	user 0.004s	sys 0.016s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4186,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:15.554177 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling MajorDeltaCompactionOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=1.000000
I20260812 06:19:15.790088 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: MajorDeltaCompactionOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.236s	user 0.184s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":694,"dirs.run_cpu_time_us":2288,"dirs.run_wall_time_us":19534,"lbm_read_time_us":11579,"lbm_reads_lt_1ms":472,"lbm_write_time_us":35293,"lbm_writes_lt_1ms":443,"mutex_wait_us":384,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:15.791087 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=15.087375
I20260812 06:19:15.835059 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.044s	user 0.024s	sys 0.017s Metrics: {"bytes_written":16820145,"delete_count":0,"lbm_write_time_us":19691,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:19:15.835515 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=2.188937
I20260812 06:19:15.844980 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.009s	user 0.001s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3607,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:15.845427 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling MajorDeltaCompactionOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=1.000000
I20260812 06:19:15.999601 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: MajorDeltaCompactionOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.154s	user 0.113s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774678,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1410,"lbm_read_time_us":12954,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28769,"lbm_writes_lt_1ms":543,"mutex_wait_us":603,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":18688,"thread_start_us":82,"threads_started":1,"update_count":2500}
I20260812 06:19:16.000577 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=10.126437
I20260812 06:19:16.038748 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.038s	user 0.019s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17321,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:16.039264 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=2.188937
I20260812 06:19:16.051599 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4695,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:16.052134 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling MajorDeltaCompactionOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=1.000000
I20260812 06:19:16.185743 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: MajorDeltaCompactionOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.133s	user 0.118s	sys 0.015s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":752,"lbm_read_time_us":9874,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24516,"lbm_writes_lt_1ms":443,"mutex_wait_us":35,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10112,"update_count":2000}
I20260812 06:19:16.186666 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=10.126437
I20260812 06:19:16.233089 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.046s	user 0.039s	sys 0.000s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17065,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:16.233614 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=2.188937
I20260812 06:19:16.244390 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4150,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:16.245155 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling FlushMRSOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=1.000000
I20260812 06:19:16.275157 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: FlushMRSOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.030s	user 0.024s	sys 0.003s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":59,"dirs.run_cpu_time_us":223,"dirs.run_wall_time_us":1937,"drs_written":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1928,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28,"spinlock_wait_cycles":4480}
I20260812 06:19:16.276381 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling LogGCOp(f30fbc36ff2142b48cc3b3041a4df84d): free 120553390 bytes of WAL
I20260812 06:19:16.276949 29027 log_reader.cc:385] T f30fbc36ff2142b48cc3b3041a4df84d: removed 12 log segments from log reader
I20260812 06:19:16.277005 29027 log.cc:1079] T f30fbc36ff2142b48cc3b3041a4df84d P 25c00dac6a354ecd93c53d8e2630db55: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/f30fbc36ff2142b48cc3b3041a4df84d/wal-000000014 (ops 66-70)
I20260812 06:19:16.277043 29027 log.cc:1079] T f30fbc36ff2142b48cc3b3041a4df84d P 25c00dac6a354ecd93c53d8e2630db55: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/f30fbc36ff2142b48cc3b3041a4df84d/wal-000000015 (ops 71-74)
I20260812 06:19:16.277078 29027 log.cc:1079] T f30fbc36ff2142b48cc3b3041a4df84d P 25c00dac6a354ecd93c53d8e2630db55: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/f30fbc36ff2142b48cc3b3041a4df84d/wal-000000016 (ops 75-79)
I20260812 06:19:16.277102 29027 log.cc:1079] T f30fbc36ff2142b48cc3b3041a4df84d P 25c00dac6a354ecd93c53d8e2630db55: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/f30fbc36ff2142b48cc3b3041a4df84d/wal-000000017 (ops 80-84)
I20260812 06:19:16.277124 29027 log.cc:1079] T f30fbc36ff2142b48cc3b3041a4df84d P 25c00dac6a354ecd93c53d8e2630db55: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/f30fbc36ff2142b48cc3b3041a4df84d/wal-000000018 (ops 85-89)
I20260812 06:19:16.277150 29027 log.cc:1079] T f30fbc36ff2142b48cc3b3041a4df84d P 25c00dac6a354ecd93c53d8e2630db55: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/f30fbc36ff2142b48cc3b3041a4df84d/wal-000000019 (ops 90-94)
I20260812 06:19:16.277184 29027 log.cc:1079] T f30fbc36ff2142b48cc3b3041a4df84d P 25c00dac6a354ecd93c53d8e2630db55: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/f30fbc36ff2142b48cc3b3041a4df84d/wal-000000020 (ops 95-99)
I20260812 06:19:16.277207 29027 log.cc:1079] T f30fbc36ff2142b48cc3b3041a4df84d P 25c00dac6a354ecd93c53d8e2630db55: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/f30fbc36ff2142b48cc3b3041a4df84d/wal-000000021 (ops 100-104)
I20260812 06:19:16.277232 29027 log.cc:1079] T f30fbc36ff2142b48cc3b3041a4df84d P 25c00dac6a354ecd93c53d8e2630db55: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/f30fbc36ff2142b48cc3b3041a4df84d/wal-000000022 (ops 105-109)
I20260812 06:19:16.277256 29027 log.cc:1079] T f30fbc36ff2142b48cc3b3041a4df84d P 25c00dac6a354ecd93c53d8e2630db55: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/f30fbc36ff2142b48cc3b3041a4df84d/wal-000000023 (ops 110-114)
I20260812 06:19:16.277277 29027 log.cc:1079] T f30fbc36ff2142b48cc3b3041a4df84d P 25c00dac6a354ecd93c53d8e2630db55: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/f30fbc36ff2142b48cc3b3041a4df84d/wal-000000024 (ops 115-118)
I20260812 06:19:16.277307 29027 log.cc:1079] T f30fbc36ff2142b48cc3b3041a4df84d P 25c00dac6a354ecd93c53d8e2630db55: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/f30fbc36ff2142b48cc3b3041a4df84d/wal-000000025 (ops 119-123)
I20260812 06:19:16.309413 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: LogGCOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.033s	user 0.000s	sys 0.031s Metrics: {}
I20260812 06:19:16.309787 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=2.188937
I20260812 06:19:16.331802 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.022s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4581,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:16.332273 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=2.188937
I20260812 06:19:16.342523 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4022,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:16.342932 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling MajorDeltaCompactionOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=1.000000
I20260812 06:19:16.520001 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: MajorDeltaCompactionOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.177s	user 0.134s	sys 0.036s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877338,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":3722,"lbm_read_time_us":12829,"lbm_reads_lt_1ms":674,"lbm_write_time_us":35295,"lbm_writes_lt_1ms":643,"mutex_wait_us":3050,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6784,"thread_start_us":88,"threads_started":1,"update_count":3000}
I20260812 06:19:16.520782 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling UndoDeltaBlockGCOp(f30fbc36ff2142b48cc3b3041a4df84d): 447 bytes on disk
I20260812 06:19:16.521306 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: UndoDeltaBlockGCOp(f30fbc36ff2142b48cc3b3041a4df84d) 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:19:16.521826 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=14.095187
I20260812 06:19:16.573551 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.052s	user 0.016s	sys 0.029s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":20834,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:16.574015 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=2.188937
I20260812 06:19:16.586176 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4314,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:16.586767 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling MajorDeltaCompactionOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=1.000000
I20260812 06:19:16.746488 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: MajorDeltaCompactionOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.160s	user 0.128s	sys 0.027s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":121,"lbm_read_time_us":9711,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31802,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":384,"update_count":2500}
I20260812 06:19:16.747227 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=12.110812
I20260812 06:19:16.790885 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.043s	user 0.030s	sys 0.012s Metrics: {"bytes_written":13661280,"delete_count":0,"lbm_write_time_us":18979,"lbm_writes_lt_1ms":336,"reinsert_count":0,"update_count":1665}
I20260812 06:19:16.791538 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=1.196750
I20260812 06:19:16.805514 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.014s	user 0.008s	sys 0.001s Metrics: {"bytes_written":2748830,"delete_count":0,"lbm_write_time_us":3644,"lbm_writes_lt_1ms":70,"reinsert_count":0,"update_count":335}
I20260812 06:19:16.806087 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling MajorDeltaCompactionOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=1.000000
I20260812 06:19:16.982795 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: MajorDeltaCompactionOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.177s	user 0.109s	sys 0.061s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672238,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":153,"lbm_read_time_us":10586,"lbm_reads_lt_1ms":464,"lbm_write_time_us":29802,"lbm_writes_lt_1ms":443,"mutex_wait_us":51,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:19:16.983394 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=14.095187
I20260812 06:19:17.038416 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.055s	user 0.026s	sys 0.019s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20962,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:17.038980 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=2.188937
I20260812 06:19:17.065670 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.026s	user 0.010s	sys 0.015s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5720,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:17.066393 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling MajorDeltaCompactionOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=1.000000
I20260812 06:19:17.244388 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: MajorDeltaCompactionOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.178s	user 0.130s	sys 0.045s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":774,"lbm_read_time_us":12772,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29005,"lbm_writes_lt_1ms":543,"mutex_wait_us":54,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:19:17.245092 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=14.095187
I20260812 06:19:17.295059 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.050s	user 0.010s	sys 0.032s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19944,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:17.295569 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=2.188937
I20260812 06:19:17.307484 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4457,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:17.307981 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling MajorDeltaCompactionOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=1.000000
I20260812 06:19:17.478229 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: MajorDeltaCompactionOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.170s	user 0.112s	sys 0.053s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":130,"lbm_read_time_us":10637,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29275,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12160,"update_count":2500}
I20260812 06:19:17.478963 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=11.118625
I20260812 06:19:17.530975 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.052s	user 0.029s	sys 0.017s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":21128,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:19:17.531529 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=2.188937
I20260812 06:19:17.543345 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.012s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3820,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:17.543798 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=2.188937
I20260812 06:19:17.553351 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.009s	user 0.001s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3633,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:17.553792 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling MajorDeltaCompactionOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=1.000000
I20260812 06:19:17.696213 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: MajorDeltaCompactionOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.142s	user 0.110s	sys 0.032s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774801,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":378,"lbm_read_time_us":9436,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29866,"lbm_writes_lt_1ms":543,"mutex_wait_us":34,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:17.697021 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=10.126437
I20260812 06:19:17.746629 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.049s	user 0.020s	sys 0.025s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":21656,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:17.747262 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=2.188937
I20260812 06:19:17.765000 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.018s	user 0.017s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6829,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:17.765718 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling FlushMRSOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=1.000000
I20260812 06:19:17.798959 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: FlushMRSOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.033s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1234475,"cfile_init":1,"dirs.queue_time_us":60,"dirs.run_cpu_time_us":236,"dirs.run_wall_time_us":1374,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1804,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:17.799803 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling LogGCOp(f30fbc36ff2142b48cc3b3041a4df84d): free 120553672 bytes of WAL
I20260812 06:19:17.800043 29027 log_reader.cc:385] T f30fbc36ff2142b48cc3b3041a4df84d: removed 12 log segments from log reader
I20260812 06:19:17.800089 29027 log.cc:1079] T f30fbc36ff2142b48cc3b3041a4df84d P 25c00dac6a354ecd93c53d8e2630db55: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/f30fbc36ff2142b48cc3b3041a4df84d/wal-000000026 (ops 124-128)
I20260812 06:19:17.800143 29027 log.cc:1079] T f30fbc36ff2142b48cc3b3041a4df84d P 25c00dac6a354ecd93c53d8e2630db55: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/f30fbc36ff2142b48cc3b3041a4df84d/wal-000000027 (ops 129-133)
I20260812 06:19:17.800186 29027 log.cc:1079] T f30fbc36ff2142b48cc3b3041a4df84d P 25c00dac6a354ecd93c53d8e2630db55: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/f30fbc36ff2142b48cc3b3041a4df84d/wal-000000028 (ops 134-138)
I20260812 06:19:17.800230 29027 log.cc:1079] T f30fbc36ff2142b48cc3b3041a4df84d P 25c00dac6a354ecd93c53d8e2630db55: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/f30fbc36ff2142b48cc3b3041a4df84d/wal-000000029 (ops 139-143)
I20260812 06:19:17.800274 29027 log.cc:1079] T f30fbc36ff2142b48cc3b3041a4df84d P 25c00dac6a354ecd93c53d8e2630db55: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/f30fbc36ff2142b48cc3b3041a4df84d/wal-000000030 (ops 144-148)
I20260812 06:19:17.800331 29027 log.cc:1079] T f30fbc36ff2142b48cc3b3041a4df84d P 25c00dac6a354ecd93c53d8e2630db55: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/f30fbc36ff2142b48cc3b3041a4df84d/wal-000000031 (ops 149-152)
I20260812 06:19:17.800372 29027 log.cc:1079] T f30fbc36ff2142b48cc3b3041a4df84d P 25c00dac6a354ecd93c53d8e2630db55: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/f30fbc36ff2142b48cc3b3041a4df84d/wal-000000032 (ops 153-157)
I20260812 06:19:17.800412 29027 log.cc:1079] T f30fbc36ff2142b48cc3b3041a4df84d P 25c00dac6a354ecd93c53d8e2630db55: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/f30fbc36ff2142b48cc3b3041a4df84d/wal-000000033 (ops 158-162)
I20260812 06:19:17.800453 29027 log.cc:1079] T f30fbc36ff2142b48cc3b3041a4df84d P 25c00dac6a354ecd93c53d8e2630db55: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/f30fbc36ff2142b48cc3b3041a4df84d/wal-000000034 (ops 163-167)
I20260812 06:19:17.800496 29027 log.cc:1079] T f30fbc36ff2142b48cc3b3041a4df84d P 25c00dac6a354ecd93c53d8e2630db55: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/f30fbc36ff2142b48cc3b3041a4df84d/wal-000000035 (ops 168-172)
I20260812 06:19:17.800536 29027 log.cc:1079] T f30fbc36ff2142b48cc3b3041a4df84d P 25c00dac6a354ecd93c53d8e2630db55: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/f30fbc36ff2142b48cc3b3041a4df84d/wal-000000036 (ops 173-176)
I20260812 06:19:17.800576 29027 log.cc:1079] T f30fbc36ff2142b48cc3b3041a4df84d P 25c00dac6a354ecd93c53d8e2630db55: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/f30fbc36ff2142b48cc3b3041a4df84d/wal-000000037 (ops 177-181)
I20260812 06:19:17.827865 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: LogGCOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.028s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:19:17.828387 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling UndoDeltaBlockGCOp(f30fbc36ff2142b48cc3b3041a4df84d): 473 bytes on disk
I20260812 06:19:17.829105 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: UndoDeltaBlockGCOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":79,"lbm_reads_lt_1ms":4}
I20260812 06:19:17.829782 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=3.181125
I20260812 06:19:17.847699 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.018s	user 0.013s	sys 0.003s Metrics: {"bytes_written":5046218,"delete_count":0,"lbm_write_time_us":7216,"lbm_writes_lt_1ms":126,"reinsert_count":0,"update_count":615}
I20260812 06:19:17.848220 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=1.196750
I20260812 06:19:17.858222 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3159080,"delete_count":0,"lbm_write_time_us":3371,"lbm_writes_lt_1ms":80,"reinsert_count":0,"update_count":385}
I20260812 06:19:17.858767 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling MajorDeltaCompactionOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=1.000000
I20260812 06:19:18.055395 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: MajorDeltaCompactionOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.196s	user 0.139s	sys 0.047s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877319,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":332,"lbm_read_time_us":13994,"lbm_reads_lt_1ms":674,"lbm_write_time_us":38550,"lbm_writes_lt_1ms":643,"mutex_wait_us":29,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2944,"thread_start_us":77,"threads_started":1,"update_count":3000}
I20260812 06:19:18.056072 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=14.095187
I20260812 06:19:18.114876 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.059s	user 0.026s	sys 0.020s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":21125,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:18.115314 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=2.188937
I20260812 06:19:18.126084 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4211,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:18.126886 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling MajorDeltaCompactionOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=1.000000
I20260812 06:19:18.236373 28838 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.085s	user 1.908s	sys 0.115s
I20260812 06:19:18.293140 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: MajorDeltaCompactionOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.166s	user 0.100s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":155,"lbm_read_time_us":11292,"lbm_reads_lt_1ms":568,"lbm_write_time_us":28623,"lbm_writes_lt_1ms":543,"mutex_wait_us":35,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:18.293860 29142 maintenance_manager.cc:419] P 25c00dac6a354ecd93c53d8e2630db55: Scheduling FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d): perf score=6.157687
I20260812 06:19:18.304872 28838 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.068s	user 0.004s	sys 0.000s
I20260812 06:19:18.305711 28838 tablet_server.cc:179] TabletServer@127.28.41.129:0 shutting down...
I20260812 06:19:18.320592 29027 maintenance_manager.cc:643] P 25c00dac6a354ecd93c53d8e2630db55: FlushDeltaMemStoresOp(f30fbc36ff2142b48cc3b3041a4df84d) complete. Timing: real 0.027s	user 0.008s	sys 0.015s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":11331,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:18.321215 28838 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:18.321624 28838 tablet_replica.cc:333] T f30fbc36ff2142b48cc3b3041a4df84d P 25c00dac6a354ecd93c53d8e2630db55: stopping tablet replica
I20260812 06:19:18.321895 28838 raft_consensus.cc:2243] T f30fbc36ff2142b48cc3b3041a4df84d P 25c00dac6a354ecd93c53d8e2630db55 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:18.322141 28838 raft_consensus.cc:2272] T f30fbc36ff2142b48cc3b3041a4df84d P 25c00dac6a354ecd93c53d8e2630db55 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:18.337182 28838 tablet_server.cc:196] TabletServer@127.28.41.129:0 shutdown complete.
I20260812 06:19:18.342340 28838 master.cc:562] Master@127.28.41.190:36423 shutting down...
I20260812 06:19:18.346539 28838 raft_consensus.cc:2243] T 00000000000000000000000000000000 P b29f20866cd047ae967eded06a04dee9 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:18.346704 28838 raft_consensus.cc:2272] T 00000000000000000000000000000000 P b29f20866cd047ae967eded06a04dee9 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:18.346758 28838 tablet_replica.cc:333] T 00000000000000000000000000000000 P b29f20866cd047ae967eded06a04dee9: stopping tablet replica
I20260812 06:19:18.360033 28838 master.cc:584] Master@127.28.41.190:36423 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5606 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:18.471555 28838 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.28.41.190:41271
I20260812 06:19:18.471922 28838 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:18.473800 29202 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:18.473968 29206 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:18.473981 28838 server_base.cc:1061] running on GCE node
W20260812 06:19:18.474182 29204 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:18.474531 28838 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:18.474576 28838 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:18.474592 28838 hybrid_clock.cc:648] HybridClock initialized: now 1786515558474592 us; error 0 us; skew 500 ppm
I20260812 06:19:18.475467 28838 webserver.cc:533] Webserver started at http://127.28.41.190:35915/ using document root <none> and password file <none>
I20260812 06:19:18.475673 28838 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:18.475737 28838 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:18.475821 28838 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:18.476210 28838 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552841366-28838-0/minicluster-data/master-0-root/instance:
uuid: "2874efc431b54da5ac03d79cf5f1378b"
format_stamp: "Formatted at 2026-08-12 06:19:18 on dist-test-slave-g170"
I20260812 06:19:18.478144 28838 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:19:18.479202 29214 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:18.479595 28838 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:18.479746 28838 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552841366-28838-0/minicluster-data/master-0-root
uuid: "2874efc431b54da5ac03d79cf5f1378b"
format_stamp: "Formatted at 2026-08-12 06:19:18 on dist-test-slave-g170"
I20260812 06:19:18.479842 28838 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552841366-28838-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552841366-28838-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552841366-28838-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:18.502384 28838 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:18.502812 28838 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:18.507256 28838 rpc_server.cc:307] RPC server started. Bound to: 127.28.41.190:41271
I20260812 06:19:18.507320 29308 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.28.41.190:41271 every 8 connection(s)
I20260812 06:19:18.508239 29309 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:18.510033 29309 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 2874efc431b54da5ac03d79cf5f1378b: Bootstrap starting.
I20260812 06:19:18.510761 29309 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 2874efc431b54da5ac03d79cf5f1378b: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:18.511715 29309 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 2874efc431b54da5ac03d79cf5f1378b: No bootstrap required, opened a new log
I20260812 06:19:18.512072 29309 raft_consensus.cc:359] T 00000000000000000000000000000000 P 2874efc431b54da5ac03d79cf5f1378b [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2874efc431b54da5ac03d79cf5f1378b" member_type: VOTER }
I20260812 06:19:18.512157 29309 raft_consensus.cc:385] T 00000000000000000000000000000000 P 2874efc431b54da5ac03d79cf5f1378b [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:18.512180 29309 raft_consensus.cc:740] T 00000000000000000000000000000000 P 2874efc431b54da5ac03d79cf5f1378b [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 2874efc431b54da5ac03d79cf5f1378b, State: Initialized, Role: FOLLOWER
I20260812 06:19:18.512319 29309 consensus_queue.cc:260] T 00000000000000000000000000000000 P 2874efc431b54da5ac03d79cf5f1378b [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: "2874efc431b54da5ac03d79cf5f1378b" member_type: VOTER }
I20260812 06:19:18.512414 29309 raft_consensus.cc:399] T 00000000000000000000000000000000 P 2874efc431b54da5ac03d79cf5f1378b [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:18.512449 29309 raft_consensus.cc:493] T 00000000000000000000000000000000 P 2874efc431b54da5ac03d79cf5f1378b [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:18.512483 29309 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 2874efc431b54da5ac03d79cf5f1378b [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:18.513152 29309 raft_consensus.cc:515] T 00000000000000000000000000000000 P 2874efc431b54da5ac03d79cf5f1378b [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2874efc431b54da5ac03d79cf5f1378b" member_type: VOTER }
I20260812 06:19:18.513263 29309 leader_election.cc:304] T 00000000000000000000000000000000 P 2874efc431b54da5ac03d79cf5f1378b [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: 2874efc431b54da5ac03d79cf5f1378b; no voters: 
I20260812 06:19:18.513392 29309 leader_election.cc:290] T 00000000000000000000000000000000 P 2874efc431b54da5ac03d79cf5f1378b [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:18.513559 29315 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 2874efc431b54da5ac03d79cf5f1378b [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:18.513804 29315 raft_consensus.cc:697] T 00000000000000000000000000000000 P 2874efc431b54da5ac03d79cf5f1378b [term 1 LEADER]: Becoming Leader. State: Replica: 2874efc431b54da5ac03d79cf5f1378b, State: Running, Role: LEADER
I20260812 06:19:18.513896 29309 sys_catalog.cc:565] T 00000000000000000000000000000000 P 2874efc431b54da5ac03d79cf5f1378b [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:18.513937 29315 consensus_queue.cc:237] T 00000000000000000000000000000000 P 2874efc431b54da5ac03d79cf5f1378b [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: "2874efc431b54da5ac03d79cf5f1378b" member_type: VOTER }
I20260812 06:19:18.514384 29316 sys_catalog.cc:455] T 00000000000000000000000000000000 P 2874efc431b54da5ac03d79cf5f1378b [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "2874efc431b54da5ac03d79cf5f1378b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2874efc431b54da5ac03d79cf5f1378b" member_type: VOTER } }
I20260812 06:19:18.514483 29316 sys_catalog.cc:458] T 00000000000000000000000000000000 P 2874efc431b54da5ac03d79cf5f1378b [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:18.514436 29319 sys_catalog.cc:455] T 00000000000000000000000000000000 P 2874efc431b54da5ac03d79cf5f1378b [sys.catalog]: SysCatalogTable state changed. Reason: New leader 2874efc431b54da5ac03d79cf5f1378b. Latest consensus state: current_term: 1 leader_uuid: "2874efc431b54da5ac03d79cf5f1378b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2874efc431b54da5ac03d79cf5f1378b" member_type: VOTER } }
I20260812 06:19:18.514536 29319 sys_catalog.cc:458] T 00000000000000000000000000000000 P 2874efc431b54da5ac03d79cf5f1378b [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:18.514732 29325 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:18.515692 29325 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:18.516007 28838 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:18.517704 29325 catalog_manager.cc:1383] Generated new cluster ID: 3aa93b9e5c7544f897cae5c386b519a8
I20260812 06:19:18.517755 29325 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:18.537547 29325 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:18.538148 29325 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:18.552925 29325 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 2874efc431b54da5ac03d79cf5f1378b: Generated new TSK 0
I20260812 06:19:18.553110 29325 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:18.580892 28838 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:18.582952 29341 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:18.583037 29344 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:18.583108 29350 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:18.583240 28838 server_base.cc:1061] running on GCE node
I20260812 06:19:18.583487 28838 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:18.583559 28838 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:18.583586 28838 hybrid_clock.cc:648] HybridClock initialized: now 1786515558583586 us; error 0 us; skew 500 ppm
I20260812 06:19:18.584463 28838 webserver.cc:533] Webserver started at http://127.28.41.129:32961/ using document root <none> and password file <none>
I20260812 06:19:18.584648 28838 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:18.584728 28838 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:18.584856 28838 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:18.585301 28838 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552841366-28838-0/minicluster-data/ts-0-root/instance:
uuid: "8c2b089665f94f8e8b0e3221b5fd4a65"
format_stamp: "Formatted at 2026-08-12 06:19:18 on dist-test-slave-g170"
I20260812 06:19:18.586872 28838 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:19:18.587862 29359 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:18.588137 28838 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:18.588236 28838 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552841366-28838-0/minicluster-data/ts-0-root
uuid: "8c2b089665f94f8e8b0e3221b5fd4a65"
format_stamp: "Formatted at 2026-08-12 06:19:18 on dist-test-slave-g170"
I20260812 06:19:18.588328 28838 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552841366-28838-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552841366-28838-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552841366-28838-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:18.593717 28838 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:18.594043 28838 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:18.594344 28838 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:18.594808 28838 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:18.594869 28838 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:18.594930 28838 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:18.594981 28838 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:18.599643 28838 rpc_server.cc:307] RPC server started. Bound to: 127.28.41.129:36765
I20260812 06:19:18.599756 29471 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.28.41.129:36765 every 8 connection(s)
I20260812 06:19:18.608997 29472 heartbeater.cc:344] Connected to a master server at 127.28.41.190:41271
I20260812 06:19:18.609099 29472 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:18.609333 29472 heartbeater.cc:507] Master 127.28.41.190:41271 requested a full tablet report, sending...
I20260812 06:19:18.609977 29247 ts_manager.cc:194] Registered new tserver with Master: 8c2b089665f94f8e8b0e3221b5fd4a65 (127.28.41.129:36765)
I20260812 06:19:18.610180 28838 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.010026567s
I20260812 06:19:18.611014 29247 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:40686
I20260812 06:19:18.618005 29247 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:40694:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:18.627430 29411 tablet_service.cc:1511] Processing CreateTablet for tablet 8e4a3d492b6a4f1b97eb6b3189efb8d8 (DEFAULT_TABLE table=heavy-update-compaction-test [id=ed07b071b19d4c3cb87ccdc483b1c47a]), partition=
I20260812 06:19:18.627737 29411 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 8e4a3d492b6a4f1b97eb6b3189efb8d8. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:18.629954 29497 tablet_bootstrap.cc:492] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65: Bootstrap starting.
I20260812 06:19:18.630892 29497 tablet_bootstrap.cc:654] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:18.632128 29497 tablet_bootstrap.cc:492] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65: No bootstrap required, opened a new log
I20260812 06:19:18.632246 29497 ts_tablet_manager.cc:1403] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:18.632881 29497 raft_consensus.cc:359] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8c2b089665f94f8e8b0e3221b5fd4a65" member_type: VOTER last_known_addr { host: "127.28.41.129" port: 36765 } }
I20260812 06:19:18.632977 29497 raft_consensus.cc:385] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:18.633035 29497 raft_consensus.cc:740] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 8c2b089665f94f8e8b0e3221b5fd4a65, State: Initialized, Role: FOLLOWER
I20260812 06:19:18.633215 29497 consensus_queue.cc:260] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65 [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: "8c2b089665f94f8e8b0e3221b5fd4a65" member_type: VOTER last_known_addr { host: "127.28.41.129" port: 36765 } }
I20260812 06:19:18.633311 29497 raft_consensus.cc:399] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:18.633368 29497 raft_consensus.cc:493] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:18.633435 29497 raft_consensus.cc:3060] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:18.634212 29497 raft_consensus.cc:515] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8c2b089665f94f8e8b0e3221b5fd4a65" member_type: VOTER last_known_addr { host: "127.28.41.129" port: 36765 } }
I20260812 06:19:18.634370 29497 leader_election.cc:304] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65 [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: 8c2b089665f94f8e8b0e3221b5fd4a65; no voters: 
I20260812 06:19:18.634610 29497 leader_election.cc:290] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:18.634743 29500 raft_consensus.cc:2804] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:18.635010 29500 raft_consensus.cc:697] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65 [term 1 LEADER]: Becoming Leader. State: Replica: 8c2b089665f94f8e8b0e3221b5fd4a65, State: Running, Role: LEADER
I20260812 06:19:18.634987 29472 heartbeater.cc:499] Master 127.28.41.190:41271 was elected leader, sending a full tablet report...
I20260812 06:19:18.634982 29497 ts_tablet_manager.cc:1434] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:19:18.635177 29500 consensus_queue.cc:237] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65 [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: "8c2b089665f94f8e8b0e3221b5fd4a65" member_type: VOTER last_known_addr { host: "127.28.41.129" port: 36765 } }
I20260812 06:19:18.636500 29247 catalog_manager.cc:5719] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65 reported cstate change: term changed from 0 to 1, leader changed from <none> to 8c2b089665f94f8e8b0e3221b5fd4a65 (127.28.41.129). New cstate: current_term: 1 leader_uuid: "8c2b089665f94f8e8b0e3221b5fd4a65" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8c2b089665f94f8e8b0e3221b5fd4a65" member_type: VOTER last_known_addr { host: "127.28.41.129" port: 36765 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:18.696410 28838 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.053s	user 0.022s	sys 0.000s
I20260812 06:19:18.850708 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling FlushMRSOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=19.054940
I20260812 06:19:19.013960 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: FlushMRSOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.163s	user 0.120s	sys 0.041s Metrics: {"bytes_written":12881834,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":89,"dirs.run_cpu_time_us":292,"dirs.run_wall_time_us":946,"drs_written":1,"lbm_read_time_us":123,"lbm_reads_lt_1ms":4,"lbm_write_time_us":42326,"lbm_writes_lt_1ms":771,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1570}
I20260812 06:19:19.014816 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling LogGCOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): free 20743831 bytes of WAL
I20260812 06:19:19.015067 29370 log_reader.cc:385] T 8e4a3d492b6a4f1b97eb6b3189efb8d8: removed 2 log segments from log reader
I20260812 06:19:19.015165 29370 log.cc:1079] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/8e4a3d492b6a4f1b97eb6b3189efb8d8/wal-000000001 (ops 1-6)
I20260812 06:19:19.015224 29370 log.cc:1079] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/8e4a3d492b6a4f1b97eb6b3189efb8d8/wal-000000002 (ops 7-11)
I20260812 06:19:19.019845 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: LogGCOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.005s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:19:19.020193 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling UndoDeltaBlockGCOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): 16411396 bytes on disk
I20260812 06:19:19.020628 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: UndoDeltaBlockGCOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4}
I20260812 06:19:19.021051 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=2.188937
I20260812 06:19:19.043094 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.022s	user 0.011s	sys 0.006s Metrics: {"bytes_written":3938559,"delete_count":0,"lbm_write_time_us":4096,"lbm_writes_lt_1ms":99,"reinsert_count":0,"update_count":480}
I20260812 06:19:19.043594 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=2.188937
I20260812 06:19:19.054474 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4150,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:19.054909 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling MajorDeltaCompactionOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=1.000000
I20260812 06:19:19.249373 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: MajorDeltaCompactionOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.194s	user 0.105s	sys 0.089s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774798,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":508,"lbm_read_time_us":13832,"lbm_reads_lt_1ms":569,"lbm_write_time_us":31893,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":332,"threads_started":5,"update_count":2500}
I20260812 06:19:19.250020 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=14.095187
I20260812 06:19:19.303064 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.053s	user 0.034s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22958,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:19.303540 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=2.188937
I20260812 06:19:19.314143 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4152,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:19.314846 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling MajorDeltaCompactionOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=1.000000
I20260812 06:19:19.525475 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: MajorDeltaCompactionOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.210s	user 0.120s	sys 0.076s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":293,"lbm_read_time_us":12594,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33982,"lbm_writes_lt_1ms":543,"mutex_wait_us":40,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":68608,"update_count":2500}
I20260812 06:19:19.526077 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=14.095187
I20260812 06:19:19.577765 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.052s	user 0.027s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20012,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:19.578298 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=2.188937
I20260812 06:19:19.593752 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.015s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102660,"delete_count":0,"lbm_write_time_us":5906,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:19.594342 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling MajorDeltaCompactionOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=1.000000
I20260812 06:19:19.756855 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: MajorDeltaCompactionOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.162s	user 0.106s	sys 0.051s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":769,"lbm_read_time_us":11120,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32602,"lbm_writes_lt_1ms":543,"mutex_wait_us":320,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4736,"update_count":2500}
I20260812 06:19:19.757516 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=11.118625
I20260812 06:19:19.799996 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.042s	user 0.026s	sys 0.013s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":18397,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:19.800652 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=2.188937
I20260812 06:19:19.826668 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.026s	user 0.009s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6160,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:19.827118 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=2.188937
I20260812 06:19:19.837774 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.010s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4042,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:19.838248 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling MajorDeltaCompactionOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=1.000000
I20260812 06:19:20.003536 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: MajorDeltaCompactionOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.165s	user 0.105s	sys 0.048s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774800,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":679,"lbm_read_time_us":11702,"lbm_reads_lt_1ms":573,"lbm_write_time_us":32452,"lbm_writes_lt_1ms":543,"mutex_wait_us":92,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10624,"update_count":2500}
I20260812 06:19:20.004289 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=14.095187
I20260812 06:19:20.057492 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.053s	user 0.033s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20408,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:20.058071 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=2.188937
I20260812 06:19:20.074214 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.016s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6406,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:20.074757 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling MajorDeltaCompactionOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=1.000000
I20260812 06:19:20.229372 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: MajorDeltaCompactionOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.154s	user 0.124s	sys 0.029s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":557,"lbm_read_time_us":13708,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30746,"lbm_writes_lt_1ms":543,"mutex_wait_us":369,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":20992,"update_count":2500}
I20260812 06:19:20.229970 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=10.126437
I20260812 06:19:20.277005 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.047s	user 0.020s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15267,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:20.277683 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=2.188937
I20260812 06:19:20.293038 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.015s	user 0.012s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5752,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:20.293604 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling FlushMRSOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=1.000000
I20260812 06:19:20.323791 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: FlushMRSOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.030s	user 0.026s	sys 0.001s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":58,"dirs.run_cpu_time_us":223,"dirs.run_wall_time_us":1394,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1533,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:20.324438 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling LogGCOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): free 112239312 bytes of WAL
I20260812 06:19:20.324641 29370 log_reader.cc:385] T 8e4a3d492b6a4f1b97eb6b3189efb8d8: removed 11 log segments from log reader
I20260812 06:19:20.324690 29370 log.cc:1079] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/8e4a3d492b6a4f1b97eb6b3189efb8d8/wal-000000003 (ops 12-16)
I20260812 06:19:20.324725 29370 log.cc:1079] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/8e4a3d492b6a4f1b97eb6b3189efb8d8/wal-000000004 (ops 17-21)
I20260812 06:19:20.324795 29370 log.cc:1079] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/8e4a3d492b6a4f1b97eb6b3189efb8d8/wal-000000005 (ops 22-26)
I20260812 06:19:20.324836 29370 log.cc:1079] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/8e4a3d492b6a4f1b97eb6b3189efb8d8/wal-000000006 (ops 27-31)
I20260812 06:19:20.324859 29370 log.cc:1079] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/8e4a3d492b6a4f1b97eb6b3189efb8d8/wal-000000007 (ops 32-36)
I20260812 06:19:20.324882 29370 log.cc:1079] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/8e4a3d492b6a4f1b97eb6b3189efb8d8/wal-000000008 (ops 37-41)
I20260812 06:19:20.324903 29370 log.cc:1079] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/8e4a3d492b6a4f1b97eb6b3189efb8d8/wal-000000009 (ops 42-46)
I20260812 06:19:20.324924 29370 log.cc:1079] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/8e4a3d492b6a4f1b97eb6b3189efb8d8/wal-000000010 (ops 47-50)
I20260812 06:19:20.324947 29370 log.cc:1079] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/8e4a3d492b6a4f1b97eb6b3189efb8d8/wal-000000011 (ops 51-55)
I20260812 06:19:20.324981 29370 log.cc:1079] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/8e4a3d492b6a4f1b97eb6b3189efb8d8/wal-000000012 (ops 56-60)
I20260812 06:19:20.325013 29370 log.cc:1079] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/8e4a3d492b6a4f1b97eb6b3189efb8d8/wal-000000013 (ops 61-65)
I20260812 06:19:20.355505 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: LogGCOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.031s	user 0.002s	sys 0.027s Metrics: {}
I20260812 06:19:20.355912 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling UndoDeltaBlockGCOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): 462 bytes on disk
I20260812 06:19:20.356340 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: UndoDeltaBlockGCOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4}
I20260812 06:19:20.356890 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=2.188937
I20260812 06:19:20.379096 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.022s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4449,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:20.379557 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=2.188937
I20260812 06:19:20.390072 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4056,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:20.390486 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling MajorDeltaCompactionOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=1.000000
I20260812 06:19:20.555718 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: MajorDeltaCompactionOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.165s	user 0.125s	sys 0.040s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877339,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":285,"lbm_read_time_us":13053,"lbm_reads_lt_1ms":674,"lbm_write_time_us":32341,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6400,"thread_start_us":90,"threads_started":1,"update_count":3000}
I20260812 06:19:20.556339 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=14.095187
I20260812 06:19:20.612850 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.056s	user 0.041s	sys 0.015s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":25831,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:19:20.613423 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=2.188937
I20260812 06:19:20.631950 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.018s	user 0.006s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6377,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:20.632529 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling MajorDeltaCompactionOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=1.000000
I20260812 06:19:20.806270 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: MajorDeltaCompactionOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.173s	user 0.121s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":321,"lbm_read_time_us":10001,"lbm_reads_lt_1ms":564,"lbm_write_time_us":36293,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":2500}
I20260812 06:19:20.807116 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=14.095187
I20260812 06:19:20.876017 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.069s	user 0.025s	sys 0.032s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":26392,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:20.876499 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=2.188937
I20260812 06:19:20.888084 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4405,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:20.888643 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling MajorDeltaCompactionOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=1.000000
I20260812 06:19:21.069136 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: MajorDeltaCompactionOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.180s	user 0.122s	sys 0.057s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1318,"lbm_read_time_us":12523,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30452,"lbm_writes_lt_1ms":543,"mutex_wait_us":360,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10624,"update_count":2500}
I20260812 06:19:21.069996 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=14.095187
I20260812 06:19:21.122032 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.052s	user 0.031s	sys 0.017s Metrics: {"bytes_written":16409910,"delete_count":0,"lbm_write_time_us":20222,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:21.122548 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=2.188937
I20260812 06:19:21.134938 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4211,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:21.135557 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling MajorDeltaCompactionOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=1.000000
I20260812 06:19:21.326795 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: MajorDeltaCompactionOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.191s	user 0.117s	sys 0.074s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774697,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":383,"lbm_read_time_us":13889,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33337,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5632,"update_count":2500}
I20260812 06:19:21.327426 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=14.095187
I20260812 06:19:21.395467 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.068s	user 0.033s	sys 0.032s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24496,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:21.396095 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=2.188937
I20260812 06:19:21.413952 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.018s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6760,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:21.414705 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling MajorDeltaCompactionOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=1.000000
I20260812 06:19:21.601413 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: MajorDeltaCompactionOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.186s	user 0.122s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":656,"lbm_read_time_us":13204,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30813,"lbm_writes_lt_1ms":543,"mutex_wait_us":40,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":32000,"update_count":2500}
I20260812 06:19:21.601861 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=14.095187
I20260812 06:19:21.651906 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.050s	user 0.038s	sys 0.009s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23615,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:21.652375 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=2.188937
I20260812 06:19:21.673610 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.021s	user 0.010s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3927,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:21.674223 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling MajorDeltaCompactionOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=1.000000
I20260812 06:19:21.875650 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: MajorDeltaCompactionOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.201s	user 0.128s	sys 0.070s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1012,"lbm_read_time_us":15239,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32327,"lbm_writes_lt_1ms":543,"mutex_wait_us":386,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4992,"update_count":2500}
I20260812 06:19:21.876420 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=14.095187
I20260812 06:19:21.928289 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.052s	user 0.026s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20442,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:21.928921 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=2.188937
I20260812 06:19:21.940646 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4219,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:21.941211 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling FlushMRSOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=1.000000
I20260812 06:19:21.980997 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: FlushMRSOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.040s	user 0.035s	sys 0.000s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":87,"dirs.run_cpu_time_us":210,"dirs.run_wall_time_us":1538,"drs_written":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2725,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:19:21.981951 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling LogGCOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): free 141338451 bytes of WAL
I20260812 06:19:21.982290 29370 log_reader.cc:385] T 8e4a3d492b6a4f1b97eb6b3189efb8d8: removed 14 log segments from log reader
I20260812 06:19:21.982366 29370 log.cc:1079] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/8e4a3d492b6a4f1b97eb6b3189efb8d8/wal-000000014 (ops 66-70)
I20260812 06:19:21.982429 29370 log.cc:1079] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/8e4a3d492b6a4f1b97eb6b3189efb8d8/wal-000000015 (ops 71-74)
I20260812 06:19:21.982493 29370 log.cc:1079] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/8e4a3d492b6a4f1b97eb6b3189efb8d8/wal-000000016 (ops 75-79)
I20260812 06:19:21.982537 29370 log.cc:1079] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/8e4a3d492b6a4f1b97eb6b3189efb8d8/wal-000000017 (ops 80-84)
I20260812 06:19:21.982579 29370 log.cc:1079] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/8e4a3d492b6a4f1b97eb6b3189efb8d8/wal-000000018 (ops 85-89)
I20260812 06:19:21.982620 29370 log.cc:1079] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/8e4a3d492b6a4f1b97eb6b3189efb8d8/wal-000000019 (ops 90-94)
I20260812 06:19:21.982661 29370 log.cc:1079] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/8e4a3d492b6a4f1b97eb6b3189efb8d8/wal-000000020 (ops 95-99)
I20260812 06:19:21.982699 29370 log.cc:1079] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/8e4a3d492b6a4f1b97eb6b3189efb8d8/wal-000000021 (ops 100-104)
I20260812 06:19:21.982725 29370 log.cc:1079] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/8e4a3d492b6a4f1b97eb6b3189efb8d8/wal-000000022 (ops 105-109)
I20260812 06:19:21.982760 29370 log.cc:1079] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/8e4a3d492b6a4f1b97eb6b3189efb8d8/wal-000000023 (ops 110-114)
I20260812 06:19:21.982801 29370 log.cc:1079] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/8e4a3d492b6a4f1b97eb6b3189efb8d8/wal-000000024 (ops 115-118)
I20260812 06:19:21.982842 29370 log.cc:1079] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/8e4a3d492b6a4f1b97eb6b3189efb8d8/wal-000000025 (ops 119-123)
I20260812 06:19:21.982884 29370 log.cc:1079] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/8e4a3d492b6a4f1b97eb6b3189efb8d8/wal-000000026 (ops 124-128)
I20260812 06:19:21.982924 29370 log.cc:1079] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/8e4a3d492b6a4f1b97eb6b3189efb8d8/wal-000000027 (ops 129-133)
I20260812 06:19:22.018852 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: LogGCOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.037s	user 0.004s	sys 0.031s Metrics: {}
I20260812 06:19:22.020046 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling UndoDeltaBlockGCOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): 493 bytes on disk
I20260812 06:19:22.020844 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: UndoDeltaBlockGCOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4}
I20260812 06:19:22.021410 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=5.165500
I20260812 06:19:22.040612 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.019s	user 0.009s	sys 0.007s Metrics: {"bytes_written":6974354,"delete_count":0,"lbm_write_time_us":7944,"lbm_writes_lt_1ms":173,"reinsert_count":0,"update_count":850}
I20260812 06:19:22.041473 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=1.000000
I20260812 06:19:22.047235 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.006s	user 0.004s	sys 0.000s Metrics: {"bytes_written":1230902,"delete_count":0,"lbm_write_time_us":1666,"lbm_writes_lt_1ms":33,"reinsert_count":0,"update_count":150}
I20260812 06:19:22.047703 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling MajorDeltaCompactionOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=1.000000
I20260812 06:19:22.323293 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: MajorDeltaCompactionOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.275s	user 0.201s	sys 0.073s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":297,"lbm_read_time_us":17680,"lbm_reads_lt_1ms":774,"lbm_write_time_us":50999,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":742,"mutex_wait_us":36,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":12288,"thread_start_us":80,"threads_started":1,"update_count":3500}
I20260812 06:19:22.323989 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=18.063937
I20260812 06:19:22.411688 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.087s	user 0.027s	sys 0.045s Metrics: {"bytes_written":20512314,"delete_count":0,"lbm_write_time_us":34006,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":501,"reinsert_count":0,"update_count":2500}
I20260812 06:19:22.412245 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=6.157687
I20260812 06:19:22.441459 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.029s	user 0.017s	sys 0.011s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":12262,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:22.442184 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling MajorDeltaCompactionOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=1.000000
I20260812 06:19:22.686024 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: MajorDeltaCompactionOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.244s	user 0.172s	sys 0.071s Metrics: {"cfile_cache_miss":732,"cfile_cache_miss_bytes":32979514,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":70,"lbm_read_time_us":21324,"lbm_reads_lt_1ms":768,"lbm_write_time_us":39160,"lbm_writes_lt_1ms":743,"mutex_wait_us":24,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":52992,"update_count":3500}
I20260812 06:19:22.687145 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=18.063937
I20260812 06:19:22.774547 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.087s	user 0.043s	sys 0.032s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":33343,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:22.775084 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=6.157687
I20260812 06:19:22.808851 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.034s	user 0.014s	sys 0.016s Metrics: {"bytes_written":8205080,"delete_count":0,"lbm_write_time_us":12683,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:22.809473 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling MajorDeltaCompactionOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=1.000000
I20260812 06:19:23.024940 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: MajorDeltaCompactionOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.215s	user 0.143s	sys 0.061s Metrics: {"cfile_cache_miss":732,"cfile_cache_miss_bytes":32979519,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1530,"lbm_read_time_us":16767,"lbm_reads_lt_1ms":764,"lbm_write_time_us":44312,"lbm_writes_lt_1ms":743,"mutex_wait_us":371,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":3500}
I20260812 06:19:23.025673 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=18.063937
I20260812 06:19:23.093339 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.067s	user 0.031s	sys 0.036s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":30603,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:19:23.094219 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=2.188937
I20260812 06:19:23.126541 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.032s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5648,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:23.127029 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=2.188937
I20260812 06:19:23.138934 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4392,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:23.139454 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling MajorDeltaCompactionOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=1.000000
I20260812 06:19:23.344481 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: MajorDeltaCompactionOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.205s	user 0.159s	sys 0.043s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32979635,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":113,"lbm_read_time_us":16146,"lbm_reads_lt_1ms":773,"lbm_write_time_us":42493,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":3500}
I20260812 06:19:23.345304 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=14.095187
I20260812 06:19:23.404902 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.059s	user 0.037s	sys 0.021s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":28528,"lbm_writes_1-10_ms":4,"lbm_writes_lt_1ms":399,"reinsert_count":0,"update_count":2000}
I20260812 06:19:23.405810 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=3.181125
I20260812 06:19:23.430600 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.023s	user 0.008s	sys 0.006s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":6237,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:23.431066 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=2.188937
I20260812 06:19:23.440340 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3464,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:23.440834 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling FlushMRSOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=1.000000
I20260812 06:19:23.474210 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: FlushMRSOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.033s	user 0.030s	sys 0.001s Metrics: {"bytes_written":1193507,"cfile_init":1,"dirs.queue_time_us":63,"dirs.run_cpu_time_us":175,"dirs.run_wall_time_us":1494,"drs_written":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1969,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29,"spinlock_wait_cycles":17280}
I20260812 06:19:23.474898 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling LogGCOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): free 112239613 bytes of WAL
I20260812 06:19:23.475132 29370 log_reader.cc:385] T 8e4a3d492b6a4f1b97eb6b3189efb8d8: removed 11 log segments from log reader
I20260812 06:19:23.475180 29370 log.cc:1079] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/8e4a3d492b6a4f1b97eb6b3189efb8d8/wal-000000028 (ops 134-138)
I20260812 06:19:23.475234 29370 log.cc:1079] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/8e4a3d492b6a4f1b97eb6b3189efb8d8/wal-000000029 (ops 139-143)
I20260812 06:19:23.475276 29370 log.cc:1079] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/8e4a3d492b6a4f1b97eb6b3189efb8d8/wal-000000030 (ops 144-148)
I20260812 06:19:23.475318 29370 log.cc:1079] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/8e4a3d492b6a4f1b97eb6b3189efb8d8/wal-000000031 (ops 149-153)
I20260812 06:19:23.475358 29370 log.cc:1079] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/8e4a3d492b6a4f1b97eb6b3189efb8d8/wal-000000032 (ops 154-158)
I20260812 06:19:23.475437 29370 log.cc:1079] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/8e4a3d492b6a4f1b97eb6b3189efb8d8/wal-000000033 (ops 159-163)
I20260812 06:19:23.475474 29370 log.cc:1079] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/8e4a3d492b6a4f1b97eb6b3189efb8d8/wal-000000034 (ops 164-168)
I20260812 06:19:23.475513 29370 log.cc:1079] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/8e4a3d492b6a4f1b97eb6b3189efb8d8/wal-000000035 (ops 169-172)
I20260812 06:19:23.475556 29370 log.cc:1079] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/8e4a3d492b6a4f1b97eb6b3189efb8d8/wal-000000036 (ops 173-177)
I20260812 06:19:23.475596 29370 log.cc:1079] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/8e4a3d492b6a4f1b97eb6b3189efb8d8/wal-000000037 (ops 178-182)
I20260812 06:19:23.475643 29370 log.cc:1079] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/8e4a3d492b6a4f1b97eb6b3189efb8d8/wal-000000038 (ops 183-187)
I20260812 06:19:23.501477 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: LogGCOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.026s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:23.501880 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling UndoDeltaBlockGCOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): 462 bytes on disk
I20260812 06:19:23.502446 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: UndoDeltaBlockGCOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4}
I20260812 06:19:23.503275 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=3.181125
I20260812 06:19:23.515620 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.012s	user 0.001s	sys 0.009s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":5067,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:23.516072 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling LogGCOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): free 12017952 bytes of WAL
I20260812 06:19:23.516319 29370 log_reader.cc:385] T 8e4a3d492b6a4f1b97eb6b3189efb8d8: removed 1 log segments from log reader
I20260812 06:19:23.516389 29370 log.cc:1079] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65: Deleting log segment in path: /tmp/dist-test-taskYJsPq7/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515552841366-28838-0/minicluster-data/ts-0-root/wals/8e4a3d492b6a4f1b97eb6b3189efb8d8/wal-000000039 (ops 188-192)
I20260812 06:19:23.518872 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: LogGCOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:19:23.519207 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=2.188937
I20260812 06:19:23.532729 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.013s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4841,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:23.533406 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling MajorDeltaCompactionOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=1.000000
I20260812 06:19:23.706784 28838 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.010s	user 1.896s	sys 0.138s
I20260812 06:19:23.752530 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: MajorDeltaCompactionOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.219s	user 0.171s	sys 0.045s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37082255,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"lbm_read_time_us":16161,"lbm_reads_lt_1ms":863,"lbm_write_time_us":47758,"lbm_writes_lt_1ms":843,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":4000}
I20260812 06:19:23.753085 29474 maintenance_manager.cc:419] P 8c2b089665f94f8e8b0e3221b5fd4a65: Scheduling FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8): perf score=14.095187
I20260812 06:19:23.797960 28838 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.091s	user 0.002s	sys 0.000s
I20260812 06:19:23.798561 28838 tablet_server.cc:179] TabletServer@127.28.41.129:0 shutting down...
I20260812 06:19:23.849943 29370 maintenance_manager.cc:643] P 8c2b089665f94f8e8b0e3221b5fd4a65: FlushDeltaMemStoresOp(8e4a3d492b6a4f1b97eb6b3189efb8d8) complete. Timing: real 0.097s	user 0.032s	sys 0.008s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":17806,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2000}
I20260812 06:19:23.850720 28838 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:23.850976 28838 tablet_replica.cc:333] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65: stopping tablet replica
I20260812 06:19:23.851145 28838 raft_consensus.cc:2243] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:23.851326 28838 raft_consensus.cc:2272] T 8e4a3d492b6a4f1b97eb6b3189efb8d8 P 8c2b089665f94f8e8b0e3221b5fd4a65 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:23.865339 28838 tablet_server.cc:196] TabletServer@127.28.41.129:0 shutdown complete.
I20260812 06:19:23.868507 28838 master.cc:562] Master@127.28.41.190:41271 shutting down...
I20260812 06:19:23.872172 28838 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 2874efc431b54da5ac03d79cf5f1378b [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:23.872351 28838 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 2874efc431b54da5ac03d79cf5f1378b [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:23.872428 28838 tablet_replica.cc:333] T 00000000000000000000000000000000 P 2874efc431b54da5ac03d79cf5f1378b: stopping tablet replica
I20260812 06:19:23.885051 28838 master.cc:584] Master@127.28.41.190:41271 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5524 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11131 ms total)

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