[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:18:47.012598 14782 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.14.111.190:40287
I20260812 06:18:47.013662 14782 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:18:47.014325 14782 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:47.021126 14794 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:47.021126 14791 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:47.021620 14802 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:47.021792 14782 server_base.cc:1061] running on GCE node
I20260812 06:18:47.022392 14782 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:47.022516 14782 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:47.022570 14782 hybrid_clock.cc:648] HybridClock initialized: now 1786515527022568 us; error 0 us; skew 500 ppm
I20260812 06:18:47.028636 14782 webserver.cc:533] Webserver started at http://127.14.111.190:40071/ using document root <none> and password file <none>
I20260812 06:18:47.029291 14782 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:47.029424 14782 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:47.029740 14782 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:47.032145 14782 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515527001727-14782-0/minicluster-data/master-0-root/instance:
uuid: "ab5370a065a8471ab55300e35431f330"
format_stamp: "Formatted at 2026-08-12 06:18:47 on dist-test-slave-7f01"
I20260812 06:18:47.036698 14782 fs_manager.cc:696] Time spent creating directory manager: real 0.004s	user 0.002s	sys 0.001s
I20260812 06:18:47.039276 14807 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:47.040438 14782 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.001s
I20260812 06:18:47.040570 14782 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515527001727-14782-0/minicluster-data/master-0-root
uuid: "ab5370a065a8471ab55300e35431f330"
format_stamp: "Formatted at 2026-08-12 06:18:47 on dist-test-slave-7f01"
I20260812 06:18:47.040680 14782 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515527001727-14782-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515527001727-14782-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515527001727-14782-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:47.052635 14782 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:47.053218 14782 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:18:47.053382 14782 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:47.060709 14782 rpc_server.cc:307] RPC server started. Bound to: 127.14.111.190:40287
I20260812 06:18:47.060750 14906 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.14.111.190:40287 every 8 connection(s)
I20260812 06:18:47.063200 14907 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:47.068931 14907 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P ab5370a065a8471ab55300e35431f330: Bootstrap starting.
I20260812 06:18:47.071342 14907 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P ab5370a065a8471ab55300e35431f330: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:47.072350 14907 log.cc:826] T 00000000000000000000000000000000 P ab5370a065a8471ab55300e35431f330: Log is configured to *not* fsync() on all Append() calls
I20260812 06:18:47.074075 14907 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P ab5370a065a8471ab55300e35431f330: No bootstrap required, opened a new log
I20260812 06:18:47.076885 14907 raft_consensus.cc:359] T 00000000000000000000000000000000 P ab5370a065a8471ab55300e35431f330 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ab5370a065a8471ab55300e35431f330" member_type: VOTER }
I20260812 06:18:47.077060 14907 raft_consensus.cc:385] T 00000000000000000000000000000000 P ab5370a065a8471ab55300e35431f330 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:47.077154 14907 raft_consensus.cc:740] T 00000000000000000000000000000000 P ab5370a065a8471ab55300e35431f330 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: ab5370a065a8471ab55300e35431f330, State: Initialized, Role: FOLLOWER
I20260812 06:18:47.077769 14907 consensus_queue.cc:260] T 00000000000000000000000000000000 P ab5370a065a8471ab55300e35431f330 [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: "ab5370a065a8471ab55300e35431f330" member_type: VOTER }
I20260812 06:18:47.077966 14907 raft_consensus.cc:399] T 00000000000000000000000000000000 P ab5370a065a8471ab55300e35431f330 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:47.078048 14907 raft_consensus.cc:493] T 00000000000000000000000000000000 P ab5370a065a8471ab55300e35431f330 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:47.078198 14907 raft_consensus.cc:3060] T 00000000000000000000000000000000 P ab5370a065a8471ab55300e35431f330 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:47.078961 14907 raft_consensus.cc:515] T 00000000000000000000000000000000 P ab5370a065a8471ab55300e35431f330 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ab5370a065a8471ab55300e35431f330" member_type: VOTER }
I20260812 06:18:47.079393 14907 leader_election.cc:304] T 00000000000000000000000000000000 P ab5370a065a8471ab55300e35431f330 [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: ab5370a065a8471ab55300e35431f330; no voters: 
I20260812 06:18:47.079705 14907 leader_election.cc:290] T 00000000000000000000000000000000 P ab5370a065a8471ab55300e35431f330 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:47.079907 14913 raft_consensus.cc:2804] T 00000000000000000000000000000000 P ab5370a065a8471ab55300e35431f330 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:47.080164 14913 raft_consensus.cc:697] T 00000000000000000000000000000000 P ab5370a065a8471ab55300e35431f330 [term 1 LEADER]: Becoming Leader. State: Replica: ab5370a065a8471ab55300e35431f330, State: Running, Role: LEADER
I20260812 06:18:47.080569 14913 consensus_queue.cc:237] T 00000000000000000000000000000000 P ab5370a065a8471ab55300e35431f330 [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: "ab5370a065a8471ab55300e35431f330" member_type: VOTER }
I20260812 06:18:47.080813 14907 sys_catalog.cc:565] T 00000000000000000000000000000000 P ab5370a065a8471ab55300e35431f330 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:47.082546 14916 sys_catalog.cc:455] T 00000000000000000000000000000000 P ab5370a065a8471ab55300e35431f330 [sys.catalog]: SysCatalogTable state changed. Reason: New leader ab5370a065a8471ab55300e35431f330. Latest consensus state: current_term: 1 leader_uuid: "ab5370a065a8471ab55300e35431f330" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ab5370a065a8471ab55300e35431f330" member_type: VOTER } }
I20260812 06:18:47.082589 14915 sys_catalog.cc:455] T 00000000000000000000000000000000 P ab5370a065a8471ab55300e35431f330 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "ab5370a065a8471ab55300e35431f330" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ab5370a065a8471ab55300e35431f330" member_type: VOTER } }
I20260812 06:18:47.082683 14916 sys_catalog.cc:458] T 00000000000000000000000000000000 P ab5370a065a8471ab55300e35431f330 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:47.082696 14915 sys_catalog.cc:458] T 00000000000000000000000000000000 P ab5370a065a8471ab55300e35431f330 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:47.083135 14782 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:18:47.085467 14940 catalog_manager.cc:1594] T 00000000000000000000000000000000 P ab5370a065a8471ab55300e35431f330: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:18:47.085561 14940 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:18:47.085634 14937 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:47.086378 14937 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:47.091437 14937 catalog_manager.cc:1383] Generated new cluster ID: e64957383ba9498aa7abcaa3d4a73e67
I20260812 06:18:47.091507 14937 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:47.113277 14937 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:47.114367 14937 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:47.130789 14937 catalog_manager.cc:6092] T 00000000000000000000000000000000 P ab5370a065a8471ab55300e35431f330: Generated new TSK 0
I20260812 06:18:47.131522 14937 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:47.148226 14782 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:47.150966 14945 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:47.150985 14948 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:47.151229 14782 server_base.cc:1061] running on GCE node
W20260812 06:18:47.151290 14950 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:47.151549 14782 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:47.151615 14782 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:47.151641 14782 hybrid_clock.cc:648] HybridClock initialized: now 1786515527151640 us; error 0 us; skew 500 ppm
I20260812 06:18:47.152655 14782 webserver.cc:533] Webserver started at http://127.14.111.129:42277/ using document root <none> and password file <none>
I20260812 06:18:47.152858 14782 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:47.152936 14782 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:47.153019 14782 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:47.153498 14782 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515527001727-14782-0/minicluster-data/ts-0-root/instance:
uuid: "82fed1b3b9e2492aa9e588684684bbec"
format_stamp: "Formatted at 2026-08-12 06:18:47 on dist-test-slave-7f01"
I20260812 06:18:47.155294 14782 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:47.156379 14956 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:47.156646 14782 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:47.156719 14782 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515527001727-14782-0/minicluster-data/ts-0-root
uuid: "82fed1b3b9e2492aa9e588684684bbec"
format_stamp: "Formatted at 2026-08-12 06:18:47 on dist-test-slave-7f01"
I20260812 06:18:47.156805 14782 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515527001727-14782-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515527001727-14782-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515527001727-14782-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:47.170140 14782 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:47.170579 14782 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:47.171080 14782 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:47.171986 14782 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:47.172039 14782 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:47.172111 14782 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:47.172148 14782 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:47.178787 14782 rpc_server.cc:307] RPC server started. Bound to: 127.14.111.129:44321
I20260812 06:18:47.178828 15052 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.14.111.129:44321 every 8 connection(s)
I20260812 06:18:47.194064 15053 heartbeater.cc:344] Connected to a master server at 127.14.111.190:40287
I20260812 06:18:47.194329 15053 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:47.194774 15053 heartbeater.cc:507] Master 127.14.111.190:40287 requested a full tablet report, sending...
I20260812 06:18:47.196365 14836 ts_manager.cc:194] Registered new tserver with Master: 82fed1b3b9e2492aa9e588684684bbec (127.14.111.129:44321)
I20260812 06:18:47.196493 14782 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.017061527s
I20260812 06:18:47.197870 14836 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:35724
I20260812 06:18:47.206699 14836 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:35740:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:18:47.220826 14999 tablet_service.cc:1511] Processing CreateTablet for tablet d5c7a2d38a2a483492f229bf13f9261c (DEFAULT_TABLE table=heavy-update-compaction-test [id=8e5cf7ccc5494d7c8cfc438aa56f263d]), partition=
I20260812 06:18:47.221401 14999 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet d5c7a2d38a2a483492f229bf13f9261c. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:47.224004 15074 tablet_bootstrap.cc:492] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec: Bootstrap starting.
I20260812 06:18:47.225225 15074 tablet_bootstrap.cc:654] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:47.226389 15074 tablet_bootstrap.cc:492] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec: No bootstrap required, opened a new log
I20260812 06:18:47.226500 15074 ts_tablet_manager.cc:1403] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:18:47.226984 15074 raft_consensus.cc:359] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "82fed1b3b9e2492aa9e588684684bbec" member_type: VOTER last_known_addr { host: "127.14.111.129" port: 44321 } }
I20260812 06:18:47.227082 15074 raft_consensus.cc:385] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:47.227104 15074 raft_consensus.cc:740] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 82fed1b3b9e2492aa9e588684684bbec, State: Initialized, Role: FOLLOWER
I20260812 06:18:47.227283 15074 consensus_queue.cc:260] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec [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: "82fed1b3b9e2492aa9e588684684bbec" member_type: VOTER last_known_addr { host: "127.14.111.129" port: 44321 } }
I20260812 06:18:47.227382 15074 raft_consensus.cc:399] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:47.227449 15074 raft_consensus.cc:493] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:47.227505 15074 raft_consensus.cc:3060] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:47.228298 15074 raft_consensus.cc:515] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "82fed1b3b9e2492aa9e588684684bbec" member_type: VOTER last_known_addr { host: "127.14.111.129" port: 44321 } }
I20260812 06:18:47.228430 15074 leader_election.cc:304] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec [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: 82fed1b3b9e2492aa9e588684684bbec; no voters: 
I20260812 06:18:47.228678 15074 leader_election.cc:290] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:47.228803 15077 raft_consensus.cc:2804] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:47.229086 15077 raft_consensus.cc:697] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec [term 1 LEADER]: Becoming Leader. State: Replica: 82fed1b3b9e2492aa9e588684684bbec, State: Running, Role: LEADER
I20260812 06:18:47.229164 15074 ts_tablet_manager.cc:1434] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:18:47.229301 15077 consensus_queue.cc:237] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec [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: "82fed1b3b9e2492aa9e588684684bbec" member_type: VOTER last_known_addr { host: "127.14.111.129" port: 44321 } }
I20260812 06:18:47.229683 15053 heartbeater.cc:499] Master 127.14.111.190:40287 was elected leader, sending a full tablet report...
I20260812 06:18:47.232308 14836 catalog_manager.cc:5719] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec reported cstate change: term changed from 0 to 1, leader changed from <none> to 82fed1b3b9e2492aa9e588684684bbec (127.14.111.129). New cstate: current_term: 1 leader_uuid: "82fed1b3b9e2492aa9e588684684bbec" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "82fed1b3b9e2492aa9e588684684bbec" member_type: VOTER last_known_addr { host: "127.14.111.129" port: 44321 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:47.302192 14782 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.061s	user 0.023s	sys 0.004s
I20260812 06:18:47.429905 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling FlushMRSOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=15.086190
I20260812 06:18:47.594703 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: FlushMRSOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.164s	user 0.118s	sys 0.036s Metrics: {"bytes_written":11897249,"cfile_init":1,"compiler_manager_pool.queue_time_us":280,"delete_count":0,"dirs.queue_time_us":76,"dirs.run_cpu_time_us":264,"dirs.run_wall_time_us":844,"drs_written":1,"lbm_read_time_us":78,"lbm_reads_lt_1ms":4,"lbm_write_time_us":39134,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":174,"threads_started":1,"update_count":1450}
I20260812 06:18:47.595971 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling LogGCOp(d5c7a2d38a2a483492f229bf13f9261c): free 20743880 bytes of WAL
I20260812 06:18:47.596267 14964 log_reader.cc:385] T d5c7a2d38a2a483492f229bf13f9261c: removed 2 log segments from log reader
I20260812 06:18:47.596333 14964 log.cc:1079] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/d5c7a2d38a2a483492f229bf13f9261c/wal-000000001 (ops 1-6)
I20260812 06:18:47.596388 14964 log.cc:1079] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/d5c7a2d38a2a483492f229bf13f9261c/wal-000000002 (ops 7-11)
I20260812 06:18:47.602284 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: LogGCOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.006s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:18:47.602612 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=2.188937
I20260812 06:18:47.626000 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.023s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6730,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:47.626451 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling UndoDeltaBlockGCOp(d5c7a2d38a2a483492f229bf13f9261c): 12719216 bytes on disk
I20260812 06:18:47.627148 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: UndoDeltaBlockGCOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4}
I20260812 06:18:47.627573 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling MajorDeltaCompactionOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=1.000000
I20260812 06:18:47.759086 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: MajorDeltaCompactionOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.131s	user 0.096s	sys 0.035s Metrics: {"cfile_cache_miss":422,"cfile_cache_miss_bytes":20262036,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":856,"lbm_read_time_us":8794,"lbm_reads_lt_1ms":450,"lbm_write_time_us":25927,"lbm_writes_lt_1ms":433,"peak_mem_usage":49238594,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":296,"threads_started":5,"update_count":1950}
I20260812 06:18:47.759591 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=10.126437
I20260812 06:18:47.801648 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.042s	user 0.023s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15994,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:47.802177 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=2.188937
I20260812 06:18:47.813941 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4372,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:47.814590 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling MajorDeltaCompactionOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=1.000000
I20260812 06:18:47.946848 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: MajorDeltaCompactionOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.132s	user 0.096s	sys 0.036s 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":376,"lbm_read_time_us":9864,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26691,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14336,"update_count":2000}
I20260812 06:18:47.947527 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=10.126437
I20260812 06:18:47.994012 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.046s	user 0.024s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17307,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:47.994491 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=2.188937
I20260812 06:18:48.006454 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4474,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:48.007030 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling MajorDeltaCompactionOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=1.000000
I20260812 06:18:48.139588 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: MajorDeltaCompactionOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.132s	user 0.106s	sys 0.025s 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":923,"lbm_read_time_us":9397,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25897,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15616,"update_count":2000}
I20260812 06:18:48.140268 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=10.126437
I20260812 06:18:48.190428 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.050s	user 0.023s	sys 0.022s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":18049,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:48.190977 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=2.188937
I20260812 06:18:48.202093 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4458,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:48.202550 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling MajorDeltaCompactionOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=1.000000
I20260812 06:18:48.368685 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: MajorDeltaCompactionOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.166s	user 0.115s	sys 0.048s 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":757,"lbm_read_time_us":12238,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25257,"lbm_writes_lt_1ms":443,"mutex_wait_us":68,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2000}
I20260812 06:18:48.369331 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=10.126437
I20260812 06:18:48.414868 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.045s	user 0.013s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16359,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:48.415403 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=2.188937
I20260812 06:18:48.426868 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4389,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:48.427426 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling MajorDeltaCompactionOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=1.000000
I20260812 06:18:48.561586 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: MajorDeltaCompactionOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.134s	user 0.114s	sys 0.019s 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":445,"lbm_read_time_us":10078,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26061,"lbm_writes_lt_1ms":443,"mutex_wait_us":67,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":2000}
I20260812 06:18:48.562299 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=10.126437
I20260812 06:18:48.596799 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.034s	user 0.021s	sys 0.011s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14995,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:48.597445 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=2.188937
I20260812 06:18:48.609633 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4630,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:48.610121 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling MajorDeltaCompactionOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=1.000000
I20260812 06:18:48.736348 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: MajorDeltaCompactionOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.126s	user 0.111s	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":231,"lbm_read_time_us":9176,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23134,"lbm_writes_lt_1ms":443,"mutex_wait_us":20,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12416,"update_count":2000}
I20260812 06:18:48.737133 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=10.126437
I20260812 06:18:48.780511 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.043s	user 0.034s	sys 0.004s Metrics: {"bytes_written":12307497,"delete_count":0,"lbm_write_time_us":16888,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:48.780980 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=2.188937
I20260812 06:18:48.792644 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4568,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:48.793282 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling MajorDeltaCompactionOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=1.000000
I20260812 06:18:48.925948 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: MajorDeltaCompactionOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.132s	user 0.080s	sys 0.052s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672284,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":685,"lbm_read_time_us":10034,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25773,"lbm_writes_lt_1ms":443,"mutex_wait_us":301,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4352,"update_count":2000}
I20260812 06:18:48.926683 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=10.126437
I20260812 06:18:48.976676 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.050s	user 0.022s	sys 0.023s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16782,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:48.977237 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=2.188937
I20260812 06:18:48.988281 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4443,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:48.988725 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling FlushMRSOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=1.000000
I20260812 06:18:49.031522 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: FlushMRSOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.043s	user 0.033s	sys 0.000s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":237,"dirs.run_wall_time_us":1326,"drs_written":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1546,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:18:49.032435 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling LogGCOp(d5c7a2d38a2a483492f229bf13f9261c): free 124257246 bytes of WAL
I20260812 06:18:49.032660 14964 log_reader.cc:385] T d5c7a2d38a2a483492f229bf13f9261c: removed 12 log segments from log reader
I20260812 06:18:49.032706 14964 log.cc:1079] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/d5c7a2d38a2a483492f229bf13f9261c/wal-000000003 (ops 12-16)
I20260812 06:18:49.032734 14964 log.cc:1079] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/d5c7a2d38a2a483492f229bf13f9261c/wal-000000004 (ops 17-21)
I20260812 06:18:49.032802 14964 log.cc:1079] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/d5c7a2d38a2a483492f229bf13f9261c/wal-000000005 (ops 22-26)
I20260812 06:18:49.032868 14964 log.cc:1079] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/d5c7a2d38a2a483492f229bf13f9261c/wal-000000006 (ops 27-30)
I20260812 06:18:49.032924 14964 log.cc:1079] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/d5c7a2d38a2a483492f229bf13f9261c/wal-000000007 (ops 31-35)
I20260812 06:18:49.032963 14964 log.cc:1079] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/d5c7a2d38a2a483492f229bf13f9261c/wal-000000008 (ops 36-40)
I20260812 06:18:49.033000 14964 log.cc:1079] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/d5c7a2d38a2a483492f229bf13f9261c/wal-000000009 (ops 41-45)
I20260812 06:18:49.033041 14964 log.cc:1079] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/d5c7a2d38a2a483492f229bf13f9261c/wal-000000010 (ops 46-50)
I20260812 06:18:49.033077 14964 log.cc:1079] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/d5c7a2d38a2a483492f229bf13f9261c/wal-000000011 (ops 51-55)
I20260812 06:18:49.033115 14964 log.cc:1079] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/d5c7a2d38a2a483492f229bf13f9261c/wal-000000012 (ops 56-60)
I20260812 06:18:49.033154 14964 log.cc:1079] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/d5c7a2d38a2a483492f229bf13f9261c/wal-000000013 (ops 61-65)
I20260812 06:18:49.033192 14964 log.cc:1079] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/d5c7a2d38a2a483492f229bf13f9261c/wal-000000014 (ops 66-70)
I20260812 06:18:49.060339 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: LogGCOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.028s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:18:49.060748 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=3.181125
I20260812 06:18:49.078725 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.018s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4588,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:49.079167 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling UndoDeltaBlockGCOp(d5c7a2d38a2a483492f229bf13f9261c): 481 bytes on disk
I20260812 06:18:49.079573 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: UndoDeltaBlockGCOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:18:49.080063 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=2.188937
I20260812 06:18:49.090070 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3902,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:49.090575 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling MajorDeltaCompactionOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=1.000000
I20260812 06:18:49.303860 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: MajorDeltaCompactionOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.213s	user 0.135s	sys 0.076s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877328,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":3728,"lbm_read_time_us":13818,"lbm_reads_lt_1ms":674,"lbm_write_time_us":36363,"lbm_writes_lt_1ms":643,"mutex_wait_us":2780,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":16128,"thread_start_us":123,"threads_started":1,"update_count":3000}
I20260812 06:18:49.304488 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=14.095187
I20260812 06:18:49.357326 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.053s	user 0.028s	sys 0.023s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":23638,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:49.357843 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=2.188937
I20260812 06:18:49.371436 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.013s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5112,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:49.372021 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling MajorDeltaCompactionOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=1.000000
I20260812 06:18:49.540970 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: MajorDeltaCompactionOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.169s	user 0.125s	sys 0.042s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":434,"lbm_read_time_us":11910,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30064,"lbm_writes_lt_1ms":543,"mutex_wait_us":110,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9600,"update_count":2500}
I20260812 06:18:49.541662 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=11.118625
I20260812 06:18:49.590664 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.049s	user 0.026s	sys 0.017s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":15057,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:49.591290 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=2.188937
I20260812 06:18:49.613458 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.022s	user 0.013s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6068,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:49.613914 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=2.188937
I20260812 06:18:49.624713 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4464,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:49.625214 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling MajorDeltaCompactionOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=1.000000
I20260812 06:18:49.811403 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: MajorDeltaCompactionOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.186s	user 0.117s	sys 0.058s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":768,"lbm_read_time_us":12478,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31038,"lbm_writes_lt_1ms":543,"mutex_wait_us":67,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:18:49.812029 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=14.095187
I20260812 06:18:49.872258 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.060s	user 0.022s	sys 0.035s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21848,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:49.872799 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=2.188937
I20260812 06:18:49.887565 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.015s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5740,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:49.888201 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling MajorDeltaCompactionOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=1.000000
I20260812 06:18:50.079486 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: MajorDeltaCompactionOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.191s	user 0.127s	sys 0.053s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":158,"lbm_read_time_us":13219,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31709,"lbm_writes_lt_1ms":543,"mutex_wait_us":49,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9856,"update_count":2500}
I20260812 06:18:50.080211 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=14.095187
I20260812 06:18:50.141790 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.061s	user 0.030s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20499,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:50.142295 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=2.188937
I20260812 06:18:50.153298 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4530,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:50.153787 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling MajorDeltaCompactionOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=1.000000
I20260812 06:18:50.348409 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: MajorDeltaCompactionOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.194s	user 0.131s	sys 0.055s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":162,"lbm_read_time_us":13263,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32577,"lbm_writes_lt_1ms":543,"mutex_wait_us":41,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":2500}
I20260812 06:18:50.349040 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=11.118625
I20260812 06:18:50.394230 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.045s	user 0.016s	sys 0.020s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":16833,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:50.394833 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=2.188937
I20260812 06:18:50.418817 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.024s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5361,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:50.419282 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=2.188937
I20260812 06:18:50.430344 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4369,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:50.430806 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling MajorDeltaCompactionOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=1.000000
I20260812 06:18:50.631150 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: MajorDeltaCompactionOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.200s	user 0.139s	sys 0.051s 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":254,"lbm_read_time_us":11979,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31923,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10496,"update_count":2500}
I20260812 06:18:50.631872 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=14.095187
I20260812 06:18:50.682855 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.051s	user 0.027s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19021,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:50.683390 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=2.188937
I20260812 06:18:50.697929 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.014s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5955,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:50.698441 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling FlushMRSOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=1.000000
I20260812 06:18:50.730487 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: FlushMRSOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.032s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":73,"dirs.run_cpu_time_us":210,"dirs.run_wall_time_us":1327,"drs_written":1,"lbm_read_time_us":35,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1780,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:50.731237 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling LogGCOp(d5c7a2d38a2a483492f229bf13f9261c): free 129320520 bytes of WAL
I20260812 06:18:50.731482 14964 log_reader.cc:385] T d5c7a2d38a2a483492f229bf13f9261c: removed 13 log segments from log reader
I20260812 06:18:50.731528 14964 log.cc:1079] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/d5c7a2d38a2a483492f229bf13f9261c/wal-000000015 (ops 71-75)
I20260812 06:18:50.731559 14964 log.cc:1079] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/d5c7a2d38a2a483492f229bf13f9261c/wal-000000016 (ops 76-80)
I20260812 06:18:50.731621 14964 log.cc:1079] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/d5c7a2d38a2a483492f229bf13f9261c/wal-000000017 (ops 81-84)
I20260812 06:18:50.731683 14964 log.cc:1079] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/d5c7a2d38a2a483492f229bf13f9261c/wal-000000018 (ops 85-89)
I20260812 06:18:50.731721 14964 log.cc:1079] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/d5c7a2d38a2a483492f229bf13f9261c/wal-000000019 (ops 90-94)
I20260812 06:18:50.731788 14964 log.cc:1079] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/d5c7a2d38a2a483492f229bf13f9261c/wal-000000020 (ops 95-99)
I20260812 06:18:50.731830 14964 log.cc:1079] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/d5c7a2d38a2a483492f229bf13f9261c/wal-000000021 (ops 100-104)
I20260812 06:18:50.731858 14964 log.cc:1079] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/d5c7a2d38a2a483492f229bf13f9261c/wal-000000022 (ops 105-109)
I20260812 06:18:50.731897 14964 log.cc:1079] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/d5c7a2d38a2a483492f229bf13f9261c/wal-000000023 (ops 110-114)
I20260812 06:18:50.731937 14964 log.cc:1079] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/d5c7a2d38a2a483492f229bf13f9261c/wal-000000024 (ops 115-119)
I20260812 06:18:50.731976 14964 log.cc:1079] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/d5c7a2d38a2a483492f229bf13f9261c/wal-000000025 (ops 120-124)
I20260812 06:18:50.732015 14964 log.cc:1079] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/d5c7a2d38a2a483492f229bf13f9261c/wal-000000026 (ops 125-128)
I20260812 06:18:50.732054 14964 log.cc:1079] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/d5c7a2d38a2a483492f229bf13f9261c/wal-000000027 (ops 129-133)
I20260812 06:18:50.760102 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: LogGCOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.029s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:18:50.761679 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=3.181125
I20260812 06:18:50.791093 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.029s	user 0.013s	sys 0.002s Metrics: {"bytes_written":4307782,"delete_count":0,"lbm_write_time_us":6430,"lbm_writes_lt_1ms":108,"reinsert_count":0,"update_count":525}
I20260812 06:18:50.791561 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling LogGCOp(d5c7a2d38a2a483492f229bf13f9261c): free 12017954 bytes of WAL
I20260812 06:18:50.791816 14964 log_reader.cc:385] T d5c7a2d38a2a483492f229bf13f9261c: removed 1 log segments from log reader
I20260812 06:18:50.791872 14964 log.cc:1079] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/d5c7a2d38a2a483492f229bf13f9261c/wal-000000028 (ops 134-138)
I20260812 06:18:50.794226 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: LogGCOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:18:50.794517 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling UndoDeltaBlockGCOp(d5c7a2d38a2a483492f229bf13f9261c): 493 bytes on disk
I20260812 06:18:50.794914 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: UndoDeltaBlockGCOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:18:50.795388 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=2.188937
I20260812 06:18:50.806938 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":3897534,"delete_count":0,"lbm_write_time_us":4105,"lbm_writes_lt_1ms":98,"reinsert_count":0,"update_count":475}
I20260812 06:18:50.807545 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling MajorDeltaCompactionOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=1.000000
I20260812 06:18:51.057811 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: MajorDeltaCompactionOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.250s	user 0.157s	sys 0.080s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979747,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1647,"lbm_read_time_us":15591,"lbm_reads_lt_1ms":774,"lbm_write_time_us":40083,"lbm_writes_lt_1ms":743,"mutex_wait_us":27,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":2688,"thread_start_us":104,"threads_started":1,"update_count":3500}
I20260812 06:18:51.058506 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=18.063937
I20260812 06:18:51.132731 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.074s	user 0.036s	sys 0.028s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":30408,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:51.133215 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=2.188937
I20260812 06:18:51.143815 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4072,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:51.144682 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling MajorDeltaCompactionOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=1.000000
I20260812 06:18:51.358553 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: MajorDeltaCompactionOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.214s	user 0.130s	sys 0.082s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":267,"lbm_read_time_us":15141,"lbm_reads_lt_1ms":672,"lbm_write_time_us":37236,"lbm_writes_lt_1ms":643,"mutex_wait_us":21,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:18:51.359211 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=14.095187
I20260812 06:18:51.409284 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.050s	user 0.035s	sys 0.013s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21878,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:51.410012 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=2.188937
I20260812 06:18:51.432950 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.023s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5521,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:51.433401 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=2.188937
I20260812 06:18:51.444401 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.011s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4467,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:51.444868 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling MajorDeltaCompactionOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=1.000000
I20260812 06:18:51.657642 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: MajorDeltaCompactionOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.213s	user 0.129s	sys 0.083s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877220,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":770,"lbm_read_time_us":15845,"lbm_reads_lt_1ms":673,"lbm_write_time_us":35294,"lbm_writes_lt_1ms":643,"mutex_wait_us":292,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":5760,"update_count":3000}
I20260812 06:18:51.658368 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=14.095187
I20260812 06:18:51.724936 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.066s	user 0.033s	sys 0.031s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":32344,"lbm_writes_1-10_ms":4,"lbm_writes_lt_1ms":399,"reinsert_count":0,"update_count":2000}
I20260812 06:18:51.726261 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=2.188937
I20260812 06:18:51.752365 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.026s	user 0.012s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6430,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:51.752868 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=2.188937
I20260812 06:18:51.763521 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4267,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:51.764029 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling MajorDeltaCompactionOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=1.000000
I20260812 06:18:51.971298 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: MajorDeltaCompactionOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.207s	user 0.133s	sys 0.074s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877219,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":152,"lbm_read_time_us":13173,"lbm_reads_lt_1ms":673,"lbm_write_time_us":37352,"lbm_writes_lt_1ms":643,"mutex_wait_us":47,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":17152,"update_count":3000}
I20260812 06:18:51.972548 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=14.095187
I20260812 06:18:52.026671 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.051s	user 0.032s	sys 0.016s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":23071,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:52.027311 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=2.188937
I20260812 06:18:52.044883 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.017s	user 0.011s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6936,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:52.045660 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling MajorDeltaCompactionOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=1.000000
I20260812 06:18:52.235594 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: MajorDeltaCompactionOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.190s	user 0.112s	sys 0.071s 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":900,"lbm_read_time_us":12483,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32799,"lbm_writes_lt_1ms":543,"mutex_wait_us":35,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2500}
I20260812 06:18:52.236274 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=14.095187
I20260812 06:18:52.297304 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.061s	user 0.038s	sys 0.011s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21993,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:52.297940 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=2.188937
I20260812 06:18:52.308893 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.011s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4354,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:52.309551 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling FlushMRSOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=1.000000
I20260812 06:18:52.346789 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: FlushMRSOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.037s	user 0.023s	sys 0.006s Metrics: {"bytes_written":1234477,"cfile_init":1,"dirs.queue_time_us":77,"dirs.run_cpu_time_us":253,"dirs.run_wall_time_us":1293,"drs_written":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1640,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:18:52.347491 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling LogGCOp(d5c7a2d38a2a483492f229bf13f9261c): free 120553644 bytes of WAL
I20260812 06:18:52.347718 14964 log_reader.cc:385] T d5c7a2d38a2a483492f229bf13f9261c: removed 12 log segments from log reader
I20260812 06:18:52.347836 14964 log.cc:1079] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/d5c7a2d38a2a483492f229bf13f9261c/wal-000000029 (ops 139-143)
I20260812 06:18:52.347886 14964 log.cc:1079] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/d5c7a2d38a2a483492f229bf13f9261c/wal-000000030 (ops 144-148)
I20260812 06:18:52.347931 14964 log.cc:1079] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/d5c7a2d38a2a483492f229bf13f9261c/wal-000000031 (ops 149-153)
I20260812 06:18:52.347965 14964 log.cc:1079] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/d5c7a2d38a2a483492f229bf13f9261c/wal-000000032 (ops 154-158)
I20260812 06:18:52.347999 14964 log.cc:1079] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/d5c7a2d38a2a483492f229bf13f9261c/wal-000000033 (ops 159-162)
I20260812 06:18:52.348040 14964 log.cc:1079] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/d5c7a2d38a2a483492f229bf13f9261c/wal-000000034 (ops 163-167)
I20260812 06:18:52.348083 14964 log.cc:1079] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/d5c7a2d38a2a483492f229bf13f9261c/wal-000000035 (ops 168-172)
I20260812 06:18:52.348121 14964 log.cc:1079] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/d5c7a2d38a2a483492f229bf13f9261c/wal-000000036 (ops 173-177)
I20260812 06:18:52.348160 14964 log.cc:1079] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/d5c7a2d38a2a483492f229bf13f9261c/wal-000000037 (ops 178-182)
I20260812 06:18:52.348199 14964 log.cc:1079] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/d5c7a2d38a2a483492f229bf13f9261c/wal-000000038 (ops 183-187)
I20260812 06:18:52.348240 14964 log.cc:1079] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/d5c7a2d38a2a483492f229bf13f9261c/wal-000000039 (ops 188-192)
I20260812 06:18:52.348281 14964 log.cc:1079] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/d5c7a2d38a2a483492f229bf13f9261c/wal-000000040 (ops 193-196)
I20260812 06:18:52.374212 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: LogGCOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.027s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:18:52.374701 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=2.188937
I20260812 06:18:52.397202 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.022s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4823,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:52.397644 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling UndoDeltaBlockGCOp(d5c7a2d38a2a483492f229bf13f9261c): 472 bytes on disk
I20260812 06:18:52.398051 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: UndoDeltaBlockGCOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4}
I20260812 06:18:52.398702 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=2.188937
I20260812 06:18:52.409276 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: FlushDeltaMemStoresOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4206,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:52.409650 15054 maintenance_manager.cc:419] P 82fed1b3b9e2492aa9e588684684bbec: Scheduling MajorDeltaCompactionOp(d5c7a2d38a2a483492f229bf13f9261c): perf score=1.000000
I20260812 06:18:52.466166 14782 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.164s	user 1.850s	sys 0.204s
I20260812 06:18:52.554102 14782 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.087s	user 0.002s	sys 0.000s
I20260812 06:18:52.554802 14782 tablet_server.cc:179] TabletServer@127.14.111.129:0 shutting down...
I20260812 06:18:52.619241 14964 maintenance_manager.cc:643] P 82fed1b3b9e2492aa9e588684684bbec: MajorDeltaCompactionOp(d5c7a2d38a2a483492f229bf13f9261c) complete. Timing: real 0.209s	user 0.128s	sys 0.079s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979750,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":968,"lbm_read_time_us":16456,"lbm_reads_lt_1ms":770,"lbm_write_time_us":34934,"lbm_writes_lt_1ms":743,"mutex_wait_us":99,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1152,"thread_start_us":71,"threads_started":1,"update_count":3500}
I20260812 06:18:52.620131 14782 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:52.620635 14782 tablet_replica.cc:333] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec: stopping tablet replica
I20260812 06:18:52.620903 14782 raft_consensus.cc:2243] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:52.621169 14782 raft_consensus.cc:2272] T d5c7a2d38a2a483492f229bf13f9261c P 82fed1b3b9e2492aa9e588684684bbec [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:52.637112 14782 tablet_server.cc:196] TabletServer@127.14.111.129:0 shutdown complete.
I20260812 06:18:52.677347 14782 master.cc:562] Master@127.14.111.190:40287 shutting down...
I20260812 06:18:52.681188 14782 raft_consensus.cc:2243] T 00000000000000000000000000000000 P ab5370a065a8471ab55300e35431f330 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:52.681401 14782 raft_consensus.cc:2272] T 00000000000000000000000000000000 P ab5370a065a8471ab55300e35431f330 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:52.681493 14782 tablet_replica.cc:333] T 00000000000000000000000000000000 P ab5370a065a8471ab55300e35431f330: stopping tablet replica
I20260812 06:18:52.693832 14782 master.cc:584] Master@127.14.111.190:40287 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5769 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:52.782111 14782 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.14.111.190:45807
I20260812 06:18:52.782543 14782 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:18:52.784986 14782 server_base.cc:1061] running on GCE node
W20260812 06:18:52.785180 15124 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:52.785130 15116 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:52.785130 15118 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:52.785547 14782 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:52.785593 14782 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:52.785609 14782 hybrid_clock.cc:648] HybridClock initialized: now 1786515532785609 us; error 0 us; skew 500 ppm
I20260812 06:18:52.786458 14782 webserver.cc:533] Webserver started at http://127.14.111.190:36929/ using document root <none> and password file <none>
I20260812 06:18:52.786634 14782 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:52.786676 14782 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:52.786791 14782 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:52.787212 14782 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515527001727-14782-0/minicluster-data/master-0-root/instance:
uuid: "d70b82a1cffc48c78e7e8eeffd03114b"
format_stamp: "Formatted at 2026-08-12 06:18:52 on dist-test-slave-7f01"
I20260812 06:18:52.788890 14782 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:18:52.789901 15131 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:52.790203 14782 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:18:52.790273 14782 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515527001727-14782-0/minicluster-data/master-0-root
uuid: "d70b82a1cffc48c78e7e8eeffd03114b"
format_stamp: "Formatted at 2026-08-12 06:18:52 on dist-test-slave-7f01"
I20260812 06:18:52.790372 14782 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515527001727-14782-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515527001727-14782-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515527001727-14782-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:52.800931 14782 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:52.801293 14782 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:52.805445 14782 rpc_server.cc:307] RPC server started. Bound to: 127.14.111.190:45807
I20260812 06:18:52.807991 15214 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.14.111.190:45807 every 8 connection(s)
I20260812 06:18:52.814128 15216 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:52.818271 15216 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P d70b82a1cffc48c78e7e8eeffd03114b: Bootstrap starting.
I20260812 06:18:52.819118 15216 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P d70b82a1cffc48c78e7e8eeffd03114b: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:52.820231 15216 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P d70b82a1cffc48c78e7e8eeffd03114b: No bootstrap required, opened a new log
I20260812 06:18:52.820644 15216 raft_consensus.cc:359] T 00000000000000000000000000000000 P d70b82a1cffc48c78e7e8eeffd03114b [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d70b82a1cffc48c78e7e8eeffd03114b" member_type: VOTER }
I20260812 06:18:52.820730 15216 raft_consensus.cc:385] T 00000000000000000000000000000000 P d70b82a1cffc48c78e7e8eeffd03114b [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:52.820753 15216 raft_consensus.cc:740] T 00000000000000000000000000000000 P d70b82a1cffc48c78e7e8eeffd03114b [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: d70b82a1cffc48c78e7e8eeffd03114b, State: Initialized, Role: FOLLOWER
I20260812 06:18:52.820915 15216 consensus_queue.cc:260] T 00000000000000000000000000000000 P d70b82a1cffc48c78e7e8eeffd03114b [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: "d70b82a1cffc48c78e7e8eeffd03114b" member_type: VOTER }
I20260812 06:18:52.820986 15216 raft_consensus.cc:399] T 00000000000000000000000000000000 P d70b82a1cffc48c78e7e8eeffd03114b [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:52.821048 15216 raft_consensus.cc:493] T 00000000000000000000000000000000 P d70b82a1cffc48c78e7e8eeffd03114b [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:52.821113 15216 raft_consensus.cc:3060] T 00000000000000000000000000000000 P d70b82a1cffc48c78e7e8eeffd03114b [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:52.821769 15216 raft_consensus.cc:515] T 00000000000000000000000000000000 P d70b82a1cffc48c78e7e8eeffd03114b [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d70b82a1cffc48c78e7e8eeffd03114b" member_type: VOTER }
I20260812 06:18:52.821910 15216 leader_election.cc:304] T 00000000000000000000000000000000 P d70b82a1cffc48c78e7e8eeffd03114b [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: d70b82a1cffc48c78e7e8eeffd03114b; no voters: 
I20260812 06:18:52.822124 15216 leader_election.cc:290] T 00000000000000000000000000000000 P d70b82a1cffc48c78e7e8eeffd03114b [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:52.822292 15220 raft_consensus.cc:2804] T 00000000000000000000000000000000 P d70b82a1cffc48c78e7e8eeffd03114b [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:52.822513 15220 raft_consensus.cc:697] T 00000000000000000000000000000000 P d70b82a1cffc48c78e7e8eeffd03114b [term 1 LEADER]: Becoming Leader. State: Replica: d70b82a1cffc48c78e7e8eeffd03114b, State: Running, Role: LEADER
I20260812 06:18:52.822608 15216 sys_catalog.cc:565] T 00000000000000000000000000000000 P d70b82a1cffc48c78e7e8eeffd03114b [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:52.822679 15220 consensus_queue.cc:237] T 00000000000000000000000000000000 P d70b82a1cffc48c78e7e8eeffd03114b [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: "d70b82a1cffc48c78e7e8eeffd03114b" member_type: VOTER }
I20260812 06:18:52.823190 15222 sys_catalog.cc:455] T 00000000000000000000000000000000 P d70b82a1cffc48c78e7e8eeffd03114b [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "d70b82a1cffc48c78e7e8eeffd03114b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d70b82a1cffc48c78e7e8eeffd03114b" member_type: VOTER } }
I20260812 06:18:52.823241 15223 sys_catalog.cc:455] T 00000000000000000000000000000000 P d70b82a1cffc48c78e7e8eeffd03114b [sys.catalog]: SysCatalogTable state changed. Reason: New leader d70b82a1cffc48c78e7e8eeffd03114b. Latest consensus state: current_term: 1 leader_uuid: "d70b82a1cffc48c78e7e8eeffd03114b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d70b82a1cffc48c78e7e8eeffd03114b" member_type: VOTER } }
I20260812 06:18:52.823349 15223 sys_catalog.cc:458] T 00000000000000000000000000000000 P d70b82a1cffc48c78e7e8eeffd03114b [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:52.823294 15222 sys_catalog.cc:458] T 00000000000000000000000000000000 P d70b82a1cffc48c78e7e8eeffd03114b [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:52.823922 15237 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:52.824597 15237 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:52.824771 14782 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:52.826449 15237 catalog_manager.cc:1383] Generated new cluster ID: bcc822cb258046fa9a56c68ff0c6a424
I20260812 06:18:52.826510 15237 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:52.842708 15237 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:52.843204 15237 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:52.848032 15237 catalog_manager.cc:6092] T 00000000000000000000000000000000 P d70b82a1cffc48c78e7e8eeffd03114b: Generated new TSK 0
I20260812 06:18:52.848176 15237 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:52.857122 14782 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:52.859189 15257 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:52.859282 15258 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:52.859223 14782 server_base.cc:1061] running on GCE node
W20260812 06:18:52.859344 15261 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:52.859547 14782 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:52.859617 14782 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:52.859644 14782 hybrid_clock.cc:648] HybridClock initialized: now 1786515532859643 us; error 0 us; skew 500 ppm
I20260812 06:18:52.860561 14782 webserver.cc:533] Webserver started at http://127.14.111.129:32841/ using document root <none> and password file <none>
I20260812 06:18:52.860740 14782 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:52.860812 14782 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:52.860934 14782 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:52.861317 14782 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515527001727-14782-0/minicluster-data/ts-0-root/instance:
uuid: "104349aabd894fe4b9fe77fed23cb62a"
format_stamp: "Formatted at 2026-08-12 06:18:52 on dist-test-slave-7f01"
I20260812 06:18:52.862744 14782 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:52.863641 15269 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:52.863895 14782 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:52.863991 14782 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515527001727-14782-0/minicluster-data/ts-0-root
uuid: "104349aabd894fe4b9fe77fed23cb62a"
format_stamp: "Formatted at 2026-08-12 06:18:52 on dist-test-slave-7f01"
I20260812 06:18:52.864076 14782 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515527001727-14782-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515527001727-14782-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515527001727-14782-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:52.870916 14782 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:52.871218 14782 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:52.871497 14782 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:52.871994 14782 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:52.872056 14782 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:52.872112 14782 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:52.872162 14782 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:52.876390 14782 rpc_server.cc:307] RPC server started. Bound to: 127.14.111.129:42855
I20260812 06:18:52.876438 15374 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.14.111.129:42855 every 8 connection(s)
I20260812 06:18:52.884786 15376 heartbeater.cc:344] Connected to a master server at 127.14.111.190:45807
I20260812 06:18:52.884912 15376 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:52.885133 15376 heartbeater.cc:507] Master 127.14.111.190:45807 requested a full tablet report, sending...
I20260812 06:18:52.885819 15154 ts_manager.cc:194] Registered new tserver with Master: 104349aabd894fe4b9fe77fed23cb62a (127.14.111.129:42855)
I20260812 06:18:52.886503 15154 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:60784
I20260812 06:18:52.886783 14782 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.009977253s
I20260812 06:18:52.894569 15154 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:60798:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:18:52.903192 15316 tablet_service.cc:1511] Processing CreateTablet for tablet cda3872074784feda57ed33256497c2a (DEFAULT_TABLE table=heavy-update-compaction-test [id=12871f5ddbe94b29893af2bee78ab8f7]), partition=
I20260812 06:18:52.903538 15316 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet cda3872074784feda57ed33256497c2a. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:52.905526 15395 tablet_bootstrap.cc:492] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a: Bootstrap starting.
I20260812 06:18:52.906646 15395 tablet_bootstrap.cc:654] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:52.907791 15395 tablet_bootstrap.cc:492] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a: No bootstrap required, opened a new log
I20260812 06:18:52.907929 15395 ts_tablet_manager.cc:1403] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:52.908354 15395 raft_consensus.cc:359] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "104349aabd894fe4b9fe77fed23cb62a" member_type: VOTER last_known_addr { host: "127.14.111.129" port: 42855 } }
I20260812 06:18:52.908463 15395 raft_consensus.cc:385] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:52.908510 15395 raft_consensus.cc:740] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 104349aabd894fe4b9fe77fed23cb62a, State: Initialized, Role: FOLLOWER
I20260812 06:18:52.908651 15395 consensus_queue.cc:260] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a [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: "104349aabd894fe4b9fe77fed23cb62a" member_type: VOTER last_known_addr { host: "127.14.111.129" port: 42855 } }
I20260812 06:18:52.908749 15395 raft_consensus.cc:399] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:52.908795 15395 raft_consensus.cc:493] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:52.908850 15395 raft_consensus.cc:3060] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:52.909838 15395 raft_consensus.cc:515] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "104349aabd894fe4b9fe77fed23cb62a" member_type: VOTER last_known_addr { host: "127.14.111.129" port: 42855 } }
I20260812 06:18:52.909994 15395 leader_election.cc:304] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a [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: 104349aabd894fe4b9fe77fed23cb62a; no voters: 
I20260812 06:18:52.910211 15395 leader_election.cc:290] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:52.910387 15398 raft_consensus.cc:2804] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:52.910650 15376 heartbeater.cc:499] Master 127.14.111.190:45807 was elected leader, sending a full tablet report...
I20260812 06:18:52.910638 15398 raft_consensus.cc:697] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a [term 1 LEADER]: Becoming Leader. State: Replica: 104349aabd894fe4b9fe77fed23cb62a, State: Running, Role: LEADER
I20260812 06:18:52.910640 15395 ts_tablet_manager.cc:1434] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:18:52.910810 15398 consensus_queue.cc:237] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a [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: "104349aabd894fe4b9fe77fed23cb62a" member_type: VOTER last_known_addr { host: "127.14.111.129" port: 42855 } }
I20260812 06:18:52.912108 15154 catalog_manager.cc:5719] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a reported cstate change: term changed from 0 to 1, leader changed from <none> to 104349aabd894fe4b9fe77fed23cb62a (127.14.111.129). New cstate: current_term: 1 leader_uuid: "104349aabd894fe4b9fe77fed23cb62a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "104349aabd894fe4b9fe77fed23cb62a" member_type: VOTER last_known_addr { host: "127.14.111.129" port: 42855 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:52.978814 14782 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.059s	user 0.019s	sys 0.006s
I20260812 06:18:53.127274 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling FlushMRSOp(cda3872074784feda57ed33256497c2a): perf score=19.054940
I20260812 06:18:53.296945 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: FlushMRSOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.169s	user 0.110s	sys 0.051s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":72,"dirs.run_cpu_time_us":172,"dirs.run_wall_time_us":825,"drs_written":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4,"lbm_write_time_us":44652,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:18:53.297799 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling LogGCOp(cda3872074784feda57ed33256497c2a): free 20743880 bytes of WAL
I20260812 06:18:53.298080 15278 log_reader.cc:385] T cda3872074784feda57ed33256497c2a: removed 2 log segments from log reader
I20260812 06:18:53.298157 15278 log.cc:1079] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/cda3872074784feda57ed33256497c2a/wal-000000001 (ops 1-6)
I20260812 06:18:53.298211 15278 log.cc:1079] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/cda3872074784feda57ed33256497c2a/wal-000000002 (ops 7-11)
I20260812 06:18:53.302680 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: LogGCOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.005s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:18:53.303133 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a): perf score=2.188937
I20260812 06:18:53.319432 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.016s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5817,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:53.320077 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling MajorDeltaCompactionOp(cda3872074784feda57ed33256497c2a): perf score=1.000000
I20260812 06:18:53.483593 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: MajorDeltaCompactionOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.163s	user 0.106s	sys 0.052s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":507,"lbm_read_time_us":11679,"lbm_reads_lt_1ms":468,"lbm_write_time_us":26233,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5120,"thread_start_us":344,"threads_started":5,"update_count":2000}
I20260812 06:18:53.484234 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a): perf score=12.110812
I20260812 06:18:53.533032 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.049s	user 0.030s	sys 0.016s Metrics: {"bytes_written":13866412,"delete_count":0,"lbm_write_time_us":20892,"lbm_writes_lt_1ms":341,"reinsert_count":0,"update_count":1690}
I20260812 06:18:53.533623 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a): perf score=1.196750
I20260812 06:18:53.557300 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.021s	user 0.002s	sys 0.009s Metrics: {"bytes_written":2953959,"delete_count":0,"lbm_write_time_us":4348,"lbm_writes_lt_1ms":75,"reinsert_count":0,"update_count":360}
I20260812 06:18:53.557837 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling UndoDeltaBlockGCOp(cda3872074784feda57ed33256497c2a): 16411393 bytes on disk
I20260812 06:18:53.558311 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: UndoDeltaBlockGCOp(cda3872074784feda57ed33256497c2a) 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:18:53.558781 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a): perf score=2.188937
I20260812 06:18:53.572269 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.013s	user 0.005s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5402,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:53.572763 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling MajorDeltaCompactionOp(cda3872074784feda57ed33256497c2a): perf score=1.000000
I20260812 06:18:53.768275 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: MajorDeltaCompactionOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.195s	user 0.128s	sys 0.058s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774776,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":770,"lbm_read_time_us":15578,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31308,"lbm_writes_lt_1ms":543,"mutex_wait_us":49,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11776,"update_count":2500}
I20260812 06:18:53.768774 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a): perf score=14.095187
I20260812 06:18:53.831928 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.063s	user 0.042s	sys 0.010s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23196,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:53.832376 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a): perf score=2.188937
I20260812 06:18:53.843303 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4480,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:53.843818 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling MajorDeltaCompactionOp(cda3872074784feda57ed33256497c2a): perf score=1.000000
I20260812 06:18:54.031256 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: MajorDeltaCompactionOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.187s	user 0.139s	sys 0.041s 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":241,"lbm_read_time_us":15142,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29801,"lbm_writes_lt_1ms":543,"mutex_wait_us":20,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9472,"update_count":2500}
I20260812 06:18:54.031796 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a): perf score=14.095187
I20260812 06:18:54.096865 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.065s	user 0.023s	sys 0.031s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19048,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:54.097476 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a): perf score=2.188937
I20260812 06:18:54.115113 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.017s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6771,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:54.115703 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling MajorDeltaCompactionOp(cda3872074784feda57ed33256497c2a): perf score=1.000000
I20260812 06:18:54.311019 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: MajorDeltaCompactionOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.195s	user 0.128s	sys 0.062s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":192,"lbm_read_time_us":13603,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32032,"lbm_writes_lt_1ms":543,"mutex_wait_us":44,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:54.311713 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a): perf score=14.095187
I20260812 06:18:54.370316 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.058s	user 0.028s	sys 0.028s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":19763,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:54.370860 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a): perf score=2.188937
I20260812 06:18:54.382979 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.012s	user 0.009s	sys 0.000s 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:18:54.383431 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling MajorDeltaCompactionOp(cda3872074784feda57ed33256497c2a): perf score=1.000000
I20260812 06:18:54.558943 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: MajorDeltaCompactionOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.175s	user 0.125s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":274,"lbm_read_time_us":13125,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27266,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2500}
I20260812 06:18:54.559652 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a): perf score=14.095187
I20260812 06:18:54.619014 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.059s	user 0.038s	sys 0.017s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":28819,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:54.619573 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a): perf score=2.188937
I20260812 06:18:54.639575 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.020s	user 0.007s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4770,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:54.640225 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling FlushMRSOp(cda3872074784feda57ed33256497c2a): perf score=1.000000
I20260812 06:18:54.671538 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: FlushMRSOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.031s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":487,"dirs.run_cpu_time_us":248,"dirs.run_wall_time_us":1376,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1392,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:18:54.672304 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling LogGCOp(cda3872074784feda57ed33256497c2a): free 112692371 bytes of WAL
I20260812 06:18:54.672583 15278 log_reader.cc:385] T cda3872074784feda57ed33256497c2a: removed 11 log segments from log reader
I20260812 06:18:54.672655 15278 log.cc:1079] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/cda3872074784feda57ed33256497c2a/wal-000000003 (ops 12-16)
I20260812 06:18:54.672708 15278 log.cc:1079] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/cda3872074784feda57ed33256497c2a/wal-000000004 (ops 17-21)
I20260812 06:18:54.672744 15278 log.cc:1079] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/cda3872074784feda57ed33256497c2a/wal-000000005 (ops 22-26)
I20260812 06:18:54.672781 15278 log.cc:1079] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/cda3872074784feda57ed33256497c2a/wal-000000006 (ops 27-31)
I20260812 06:18:54.672816 15278 log.cc:1079] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/cda3872074784feda57ed33256497c2a/wal-000000007 (ops 32-36)
I20260812 06:18:54.672854 15278 log.cc:1079] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/cda3872074784feda57ed33256497c2a/wal-000000008 (ops 37-41)
I20260812 06:18:54.672888 15278 log.cc:1079] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/cda3872074784feda57ed33256497c2a/wal-000000009 (ops 42-46)
I20260812 06:18:54.672952 15278 log.cc:1079] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/cda3872074784feda57ed33256497c2a/wal-000000010 (ops 47-51)
I20260812 06:18:54.672989 15278 log.cc:1079] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/cda3872074784feda57ed33256497c2a/wal-000000011 (ops 52-56)
I20260812 06:18:54.673026 15278 log.cc:1079] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/cda3872074784feda57ed33256497c2a/wal-000000012 (ops 57-61)
I20260812 06:18:54.673063 15278 log.cc:1079] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/cda3872074784feda57ed33256497c2a/wal-000000013 (ops 62-66)
I20260812 06:18:54.697949 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: LogGCOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.025s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:18:54.698431 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a): perf score=3.181125
I20260812 06:18:54.715651 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.017s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":4559,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:54.716146 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling LogGCOp(cda3872074784feda57ed33256497c2a): free 11564875 bytes of WAL
I20260812 06:18:54.716382 15278 log_reader.cc:385] T cda3872074784feda57ed33256497c2a: removed 1 log segments from log reader
I20260812 06:18:54.716444 15278 log.cc:1079] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/cda3872074784feda57ed33256497c2a/wal-000000014 (ops 67-70)
I20260812 06:18:54.719312 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: LogGCOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:18:54.719641 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a): perf score=2.188937
I20260812 06:18:54.734285 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.014s	user 0.003s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5470,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:54.734822 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling MajorDeltaCompactionOp(cda3872074784feda57ed33256497c2a): perf score=1.000000
I20260812 06:18:54.991299 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: MajorDeltaCompactionOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.256s	user 0.138s	sys 0.113s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979738,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":210,"lbm_read_time_us":15935,"lbm_reads_lt_1ms":774,"lbm_write_time_us":40316,"lbm_writes_lt_1ms":743,"mutex_wait_us":74,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":86272,"thread_start_us":106,"threads_started":1,"update_count":3500}
I20260812 06:18:54.992866 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a): perf score=18.063937
I20260812 06:18:55.072618 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.080s	user 0.041s	sys 0.025s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":30427,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:55.073148 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling UndoDeltaBlockGCOp(cda3872074784feda57ed33256497c2a): 463 bytes on disk
I20260812 06:18:55.073637 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: UndoDeltaBlockGCOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":67,"lbm_reads_lt_1ms":4}
I20260812 06:18:55.074187 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a): perf score=2.188937
I20260812 06:18:55.090704 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.016s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6404,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:55.091269 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling MajorDeltaCompactionOp(cda3872074784feda57ed33256497c2a): perf score=1.000000
I20260812 06:18:55.304545 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: MajorDeltaCompactionOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.213s	user 0.128s	sys 0.079s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877103,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":344,"lbm_read_time_us":16081,"lbm_reads_lt_1ms":672,"lbm_write_time_us":33830,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":3000}
I20260812 06:18:55.305605 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a): perf score=16.079562
I20260812 06:18:55.375029 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.069s	user 0.031s	sys 0.021s Metrics: {"bytes_written":17640627,"delete_count":0,"lbm_write_time_us":25330,"lbm_writes_lt_1ms":433,"reinsert_count":0,"update_count":2150}
I20260812 06:18:55.375597 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a): perf score=5.165500
I20260812 06:18:55.402916 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.027s	user 0.012s	sys 0.012s Metrics: {"bytes_written":6974361,"delete_count":0,"lbm_write_time_us":11817,"lbm_writes_lt_1ms":173,"reinsert_count":0,"update_count":850}
I20260812 06:18:55.403450 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling MajorDeltaCompactionOp(cda3872074784feda57ed33256497c2a): perf score=1.000000
I20260812 06:18:55.666401 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: MajorDeltaCompactionOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.263s	user 0.177s	sys 0.074s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877110,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":341,"lbm_read_time_us":18303,"lbm_reads_lt_1ms":672,"lbm_write_time_us":41268,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":16000,"update_count":3000}
I20260812 06:18:55.671351 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a): perf score=18.063937
I20260812 06:18:55.743652 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.072s	user 0.041s	sys 0.020s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":30235,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:55.744269 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a): perf score=2.188937
I20260812 06:18:55.755555 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4335,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:55.756433 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling MajorDeltaCompactionOp(cda3872074784feda57ed33256497c2a): perf score=1.000000
I20260812 06:18:55.973654 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: MajorDeltaCompactionOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.217s	user 0.118s	sys 0.096s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877105,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":763,"lbm_read_time_us":14525,"lbm_reads_lt_1ms":672,"lbm_write_time_us":36627,"lbm_writes_lt_1ms":643,"mutex_wait_us":291,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12416,"update_count":3000}
I20260812 06:18:55.974254 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a): perf score=15.087375
I20260812 06:18:56.050601 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.076s	user 0.020s	sys 0.040s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":30139,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":411,"reinsert_count":0,"update_count":2050}
I20260812 06:18:56.051138 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a): perf score=6.157687
I20260812 06:18:56.074954 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.024s	user 0.008s	sys 0.012s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":9818,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:18:56.075443 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling MajorDeltaCompactionOp(cda3872074784feda57ed33256497c2a): perf score=1.000000
I20260812 06:18:56.296528 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: MajorDeltaCompactionOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.221s	user 0.123s	sys 0.096s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877101,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":247,"lbm_read_time_us":16601,"lbm_reads_lt_1ms":672,"lbm_write_time_us":36288,"lbm_writes_lt_1ms":643,"mutex_wait_us":92,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":3000}
I20260812 06:18:56.297832 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a): perf score=16.079562
I20260812 06:18:56.353190 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.055s	user 0.018s	sys 0.032s Metrics: {"bytes_written":17681648,"delete_count":0,"lbm_write_time_us":23734,"lbm_writes_lt_1ms":434,"reinsert_count":0,"update_count":2155}
I20260812 06:18:56.353696 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a): perf score=2.188937
I20260812 06:18:56.368914 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.015s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3241134,"delete_count":0,"lbm_write_time_us":3541,"lbm_writes_lt_1ms":82,"reinsert_count":0,"update_count":395}
I20260812 06:18:56.369376 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a): perf score=2.188937
I20260812 06:18:56.379195 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.010s	user 0.005s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3985,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:56.379627 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling FlushMRSOp(cda3872074784feda57ed33256497c2a): perf score=1.000000
I20260812 06:18:56.416823 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: FlushMRSOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.037s	user 0.029s	sys 0.007s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":78,"dirs.run_cpu_time_us":228,"dirs.run_wall_time_us":1290,"drs_written":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2367,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:56.417538 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling LogGCOp(cda3872074784feda57ed33256497c2a): free 121006444 bytes of WAL
I20260812 06:18:56.417766 15278 log_reader.cc:385] T cda3872074784feda57ed33256497c2a: removed 12 log segments from log reader
I20260812 06:18:56.417829 15278 log.cc:1079] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/cda3872074784feda57ed33256497c2a/wal-000000015 (ops 71-75)
I20260812 06:18:56.417886 15278 log.cc:1079] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/cda3872074784feda57ed33256497c2a/wal-000000016 (ops 76-80)
I20260812 06:18:56.417943 15278 log.cc:1079] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/cda3872074784feda57ed33256497c2a/wal-000000017 (ops 81-85)
I20260812 06:18:56.417985 15278 log.cc:1079] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/cda3872074784feda57ed33256497c2a/wal-000000018 (ops 86-90)
I20260812 06:18:56.418022 15278 log.cc:1079] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/cda3872074784feda57ed33256497c2a/wal-000000019 (ops 91-94)
I20260812 06:18:56.418061 15278 log.cc:1079] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/cda3872074784feda57ed33256497c2a/wal-000000020 (ops 95-99)
I20260812 06:18:56.418097 15278 log.cc:1079] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/cda3872074784feda57ed33256497c2a/wal-000000021 (ops 100-104)
I20260812 06:18:56.418133 15278 log.cc:1079] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/cda3872074784feda57ed33256497c2a/wal-000000022 (ops 105-109)
I20260812 06:18:56.418170 15278 log.cc:1079] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/cda3872074784feda57ed33256497c2a/wal-000000023 (ops 110-114)
I20260812 06:18:56.418206 15278 log.cc:1079] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/cda3872074784feda57ed33256497c2a/wal-000000024 (ops 115-119)
I20260812 06:18:56.418244 15278 log.cc:1079] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/cda3872074784feda57ed33256497c2a/wal-000000025 (ops 120-124)
I20260812 06:18:56.418280 15278 log.cc:1079] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/cda3872074784feda57ed33256497c2a/wal-000000026 (ops 125-129)
I20260812 06:18:56.445575 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: LogGCOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.028s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:18:56.446043 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling UndoDeltaBlockGCOp(cda3872074784feda57ed33256497c2a): 492 bytes on disk
I20260812 06:18:56.446799 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: UndoDeltaBlockGCOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":77,"lbm_reads_lt_1ms":4}
I20260812 06:18:56.447425 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a): perf score=3.181125
I20260812 06:18:56.462945 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.015s	user 0.002s	sys 0.009s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":5266,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:56.463378 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a): perf score=2.188937
I20260812 06:18:56.473877 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4440,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:56.474352 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling MajorDeltaCompactionOp(cda3872074784feda57ed33256497c2a): perf score=1.000000
I20260812 06:18:56.733183 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: MajorDeltaCompactionOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.259s	user 0.165s	sys 0.088s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37082239,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":5880,"dirs.run_cpu_time_us":872,"dirs.run_wall_time_us":10178,"lbm_read_time_us":20076,"lbm_reads_lt_1ms":875,"lbm_write_time_us":48788,"lbm_writes_lt_1ms":843,"mutex_wait_us":5199,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":54912,"update_count":4000}
I20260812 06:18:56.733965 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a): perf score=18.063937
I20260812 06:18:56.798794 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.065s	user 0.046s	sys 0.016s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":29975,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:56.799331 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a): perf score=2.188937
I20260812 06:18:56.812175 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.013s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5302,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:56.812726 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling MajorDeltaCompactionOp(cda3872074784feda57ed33256497c2a): perf score=1.000000
I20260812 06:18:57.007967 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: MajorDeltaCompactionOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.192s	user 0.152s	sys 0.036s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877103,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":893,"lbm_read_time_us":14841,"lbm_reads_lt_1ms":672,"lbm_write_time_us":41369,"lbm_writes_lt_1ms":643,"mutex_wait_us":65,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":21248,"update_count":3000}
I20260812 06:18:57.008833 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a): perf score=14.095187
I20260812 06:18:57.062629 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.053s	user 0.022s	sys 0.028s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":27318,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:18:57.063206 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a): perf score=2.188937
I20260812 06:18:57.081081 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.018s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6196,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:57.081555 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling MajorDeltaCompactionOp(cda3872074784feda57ed33256497c2a): perf score=1.000000
I20260812 06:18:57.249737 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: MajorDeltaCompactionOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.168s	user 0.116s	sys 0.041s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":192,"lbm_read_time_us":12196,"lbm_reads_lt_1ms":564,"lbm_write_time_us":32087,"lbm_writes_lt_1ms":543,"mutex_wait_us":69,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2500}
I20260812 06:18:57.250391 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a): perf score=14.095187
I20260812 06:18:57.309980 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.059s	user 0.038s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23366,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:57.310451 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a): perf score=2.188937
I20260812 06:18:57.326545 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.016s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6038,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:57.327201 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling MajorDeltaCompactionOp(cda3872074784feda57ed33256497c2a): perf score=1.000000
I20260812 06:18:57.527000 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: MajorDeltaCompactionOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.200s	user 0.126s	sys 0.069s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":243,"lbm_read_time_us":14600,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33164,"lbm_writes_lt_1ms":543,"mutex_wait_us":27,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":231168,"update_count":2500}
I20260812 06:18:57.527806 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a): perf score=14.095187
I20260812 06:18:57.590898 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.063s	user 0.030s	sys 0.020s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":24388,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:57.591409 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a): perf score=2.188937
I20260812 06:18:57.603714 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4313,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:57.604310 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling MajorDeltaCompactionOp(cda3872074784feda57ed33256497c2a): perf score=1.000000
I20260812 06:18:57.773206 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: MajorDeltaCompactionOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.169s	user 0.115s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":242,"lbm_read_time_us":12073,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29599,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":22528,"update_count":2500}
I20260812 06:18:57.773805 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a): perf score=14.095187
I20260812 06:18:57.830996 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.057s	user 0.029s	sys 0.025s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24659,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:57.831629 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a): perf score=2.188937
I20260812 06:18:57.849579 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.018s	user 0.015s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6974,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:57.850088 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling FlushMRSOp(cda3872074784feda57ed33256497c2a): perf score=1.000000
I20260812 06:18:57.891491 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: FlushMRSOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.041s	user 0.033s	sys 0.004s Metrics: {"bytes_written":1193507,"cfile_init":1,"dirs.queue_time_us":57,"dirs.run_cpu_time_us":255,"dirs.run_wall_time_us":1286,"drs_written":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2251,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:18:57.892556 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling LogGCOp(cda3872074784feda57ed33256497c2a): free 124710570 bytes of WAL
I20260812 06:18:57.893002 15278 log_reader.cc:385] T cda3872074784feda57ed33256497c2a: removed 12 log segments from log reader
I20260812 06:18:57.893110 15278 log.cc:1079] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/cda3872074784feda57ed33256497c2a/wal-000000027 (ops 130-134)
I20260812 06:18:57.893188 15278 log.cc:1079] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/cda3872074784feda57ed33256497c2a/wal-000000028 (ops 135-139)
I20260812 06:18:57.893245 15278 log.cc:1079] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/cda3872074784feda57ed33256497c2a/wal-000000029 (ops 140-144)
I20260812 06:18:57.893283 15278 log.cc:1079] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/cda3872074784feda57ed33256497c2a/wal-000000030 (ops 145-149)
I20260812 06:18:57.893333 15278 log.cc:1079] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/cda3872074784feda57ed33256497c2a/wal-000000031 (ops 150-154)
I20260812 06:18:57.893381 15278 log.cc:1079] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/cda3872074784feda57ed33256497c2a/wal-000000032 (ops 155-159)
I20260812 06:18:57.893416 15278 log.cc:1079] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/cda3872074784feda57ed33256497c2a/wal-000000033 (ops 160-164)
I20260812 06:18:57.893445 15278 log.cc:1079] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/cda3872074784feda57ed33256497c2a/wal-000000034 (ops 165-169)
I20260812 06:18:57.893474 15278 log.cc:1079] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/cda3872074784feda57ed33256497c2a/wal-000000035 (ops 170-174)
I20260812 06:18:57.893503 15278 log.cc:1079] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/cda3872074784feda57ed33256497c2a/wal-000000036 (ops 175-179)
I20260812 06:18:57.893543 15278 log.cc:1079] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/cda3872074784feda57ed33256497c2a/wal-000000037 (ops 180-184)
I20260812 06:18:57.893631 15278 log.cc:1079] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a: Deleting log segment in path: /tmp/dist-test-taskiNiE8o/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515527001727-14782-0/minicluster-data/ts-0-root/wals/cda3872074784feda57ed33256497c2a/wal-000000038 (ops 185-189)
I20260812 06:18:57.922561 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: LogGCOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.030s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:18:57.923014 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a): perf score=6.157687
I20260812 06:18:57.945925 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.023s	user 0.013s	sys 0.007s Metrics: {"bytes_written":7876885,"delete_count":0,"lbm_write_time_us":9155,"lbm_writes_lt_1ms":195,"reinsert_count":0,"update_count":960}
I20260812 06:18:57.946509 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling UndoDeltaBlockGCOp(cda3872074784feda57ed33256497c2a): 465 bytes on disk
I20260812 06:18:57.947674 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: UndoDeltaBlockGCOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":84,"lbm_reads_lt_1ms":4}
I20260812 06:18:57.948613 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling MajorDeltaCompactionOp(cda3872074784feda57ed33256497c2a): perf score=1.000000
I20260812 06:18:58.172425 14782 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.194s	user 1.881s	sys 0.220s
I20260812 06:18:58.174896 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: MajorDeltaCompactionOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.226s	user 0.135s	sys 0.080s Metrics: {"cfile_cache_miss":725,"cfile_cache_miss_bytes":32651439,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":750,"lbm_read_time_us":16428,"lbm_reads_lt_1ms":757,"lbm_write_time_us":37835,"lbm_writes_lt_1ms":735,"mutex_wait_us":91,"peak_mem_usage":86600380,"reinsert_count":0,"spinlock_wait_cycles":9728,"thread_start_us":85,"threads_started":1,"update_count":3460}
I20260812 06:18:58.175571 15377 maintenance_manager.cc:419] P 104349aabd894fe4b9fe77fed23cb62a: Scheduling FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a): perf score=19.056125
I20260812 06:18:58.202534 14782 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.030s	user 0.001s	sys 0.000s
I20260812 06:18:58.203092 14782 tablet_server.cc:179] TabletServer@127.14.111.129:0 shutting down...
I20260812 06:18:58.232784 15278 maintenance_manager.cc:643] P 104349aabd894fe4b9fe77fed23cb62a: FlushDeltaMemStoresOp(cda3872074784feda57ed33256497c2a) complete. Timing: real 0.057s	user 0.033s	sys 0.023s Metrics: {"bytes_written":20840512,"delete_count":0,"lbm_write_time_us":26361,"lbm_writes_lt_1ms":511,"reinsert_count":0,"update_count":2540}
I20260812 06:18:58.233428 14782 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:58.233651 14782 tablet_replica.cc:333] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a: stopping tablet replica
I20260812 06:18:58.233800 14782 raft_consensus.cc:2243] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:58.233978 14782 raft_consensus.cc:2272] T cda3872074784feda57ed33256497c2a P 104349aabd894fe4b9fe77fed23cb62a [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:58.237069 14782 tablet_server.cc:196] TabletServer@127.14.111.129:0 shutdown complete.
I20260812 06:18:58.239923 14782 master.cc:562] Master@127.14.111.190:45807 shutting down...
I20260812 06:18:58.243459 14782 raft_consensus.cc:2243] T 00000000000000000000000000000000 P d70b82a1cffc48c78e7e8eeffd03114b [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:58.243606 14782 raft_consensus.cc:2272] T 00000000000000000000000000000000 P d70b82a1cffc48c78e7e8eeffd03114b [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:58.243680 14782 tablet_replica.cc:333] T 00000000000000000000000000000000 P d70b82a1cffc48c78e7e8eeffd03114b: stopping tablet replica
I20260812 06:18:58.255604 14782 master.cc:584] Master@127.14.111.190:45807 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5562 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11333 ms total)

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