[==========] 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:45.965531 10760 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.10.130.62:37049
I20260812 06:18:45.966612 10760 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:45.967226 10760 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:45.973977 10772 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:45.974043 10760 server_base.cc:1061] running on GCE node
W20260812 06:18:45.973990 10769 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:45.974282 10770 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:45.974848 10760 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:45.974942 10760 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:45.974972 10760 hybrid_clock.cc:648] HybridClock initialized: now 1786515525974970 us; error 0 us; skew 500 ppm
I20260812 06:18:45.976949 10760 webserver.cc:533] Webserver started at http://127.10.130.62:41169/ using document root <none> and password file <none>
I20260812 06:18:45.977532 10760 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:45.977598 10760 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:45.977830 10760 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:45.979642 10760 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515525954692-10760-0/minicluster-data/master-0-root/instance:
uuid: "f8df717c1f0741a8a056fba615275b56"
format_stamp: "Formatted at 2026-08-12 06:18:45 on dist-test-slave-6bbx"
I20260812 06:18:45.983510 10760 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:18:45.986131 10781 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:45.987397 10760 fs_manager.cc:730] Time spent opening block manager: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:18:45.987534 10760 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515525954692-10760-0/minicluster-data/master-0-root
uuid: "f8df717c1f0741a8a056fba615275b56"
format_stamp: "Formatted at 2026-08-12 06:18:45 on dist-test-slave-6bbx"
I20260812 06:18:45.987649 10760 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515525954692-10760-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515525954692-10760-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515525954692-10760-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:46.005509 10760 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:46.006206 10760 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:46.006378 10760 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:46.015723 10760 rpc_server.cc:307] RPC server started. Bound to: 127.10.130.62:37049
I20260812 06:18:46.015723 10859 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.10.130.62:37049 every 8 connection(s)
I20260812 06:18:46.018076 10861 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:46.023716 10861 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P f8df717c1f0741a8a056fba615275b56: Bootstrap starting.
I20260812 06:18:46.026186 10861 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P f8df717c1f0741a8a056fba615275b56: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:46.027150 10861 log.cc:826] T 00000000000000000000000000000000 P f8df717c1f0741a8a056fba615275b56: Log is configured to *not* fsync() on all Append() calls
I20260812 06:18:46.029168 10861 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P f8df717c1f0741a8a056fba615275b56: No bootstrap required, opened a new log
I20260812 06:18:46.032187 10861 raft_consensus.cc:359] T 00000000000000000000000000000000 P f8df717c1f0741a8a056fba615275b56 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f8df717c1f0741a8a056fba615275b56" member_type: VOTER }
I20260812 06:18:46.032383 10861 raft_consensus.cc:385] T 00000000000000000000000000000000 P f8df717c1f0741a8a056fba615275b56 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:46.032444 10861 raft_consensus.cc:740] T 00000000000000000000000000000000 P f8df717c1f0741a8a056fba615275b56 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: f8df717c1f0741a8a056fba615275b56, State: Initialized, Role: FOLLOWER
I20260812 06:18:46.033092 10861 consensus_queue.cc:260] T 00000000000000000000000000000000 P f8df717c1f0741a8a056fba615275b56 [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: "f8df717c1f0741a8a056fba615275b56" member_type: VOTER }
I20260812 06:18:46.033249 10861 raft_consensus.cc:399] T 00000000000000000000000000000000 P f8df717c1f0741a8a056fba615275b56 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:46.033313 10861 raft_consensus.cc:493] T 00000000000000000000000000000000 P f8df717c1f0741a8a056fba615275b56 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:46.033433 10861 raft_consensus.cc:3060] T 00000000000000000000000000000000 P f8df717c1f0741a8a056fba615275b56 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:46.034261 10861 raft_consensus.cc:515] T 00000000000000000000000000000000 P f8df717c1f0741a8a056fba615275b56 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f8df717c1f0741a8a056fba615275b56" member_type: VOTER }
I20260812 06:18:46.034695 10861 leader_election.cc:304] T 00000000000000000000000000000000 P f8df717c1f0741a8a056fba615275b56 [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: f8df717c1f0741a8a056fba615275b56; no voters: 
I20260812 06:18:46.035027 10861 leader_election.cc:290] T 00000000000000000000000000000000 P f8df717c1f0741a8a056fba615275b56 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:46.035154 10864 raft_consensus.cc:2804] T 00000000000000000000000000000000 P f8df717c1f0741a8a056fba615275b56 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:46.035425 10864 raft_consensus.cc:697] T 00000000000000000000000000000000 P f8df717c1f0741a8a056fba615275b56 [term 1 LEADER]: Becoming Leader. State: Replica: f8df717c1f0741a8a056fba615275b56, State: Running, Role: LEADER
I20260812 06:18:46.035866 10864 consensus_queue.cc:237] T 00000000000000000000000000000000 P f8df717c1f0741a8a056fba615275b56 [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: "f8df717c1f0741a8a056fba615275b56" member_type: VOTER }
I20260812 06:18:46.036069 10861 sys_catalog.cc:565] T 00000000000000000000000000000000 P f8df717c1f0741a8a056fba615275b56 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:46.037612 10866 sys_catalog.cc:455] T 00000000000000000000000000000000 P f8df717c1f0741a8a056fba615275b56 [sys.catalog]: SysCatalogTable state changed. Reason: New leader f8df717c1f0741a8a056fba615275b56. Latest consensus state: current_term: 1 leader_uuid: "f8df717c1f0741a8a056fba615275b56" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f8df717c1f0741a8a056fba615275b56" member_type: VOTER } }
I20260812 06:18:46.037653 10865 sys_catalog.cc:455] T 00000000000000000000000000000000 P f8df717c1f0741a8a056fba615275b56 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "f8df717c1f0741a8a056fba615275b56" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f8df717c1f0741a8a056fba615275b56" member_type: VOTER } }
I20260812 06:18:46.037720 10866 sys_catalog.cc:458] T 00000000000000000000000000000000 P f8df717c1f0741a8a056fba615275b56 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:46.037778 10865 sys_catalog.cc:458] T 00000000000000000000000000000000 P f8df717c1f0741a8a056fba615275b56 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:46.038131 10882 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:46.038393 10760 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:46.040575 10882 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:46.045110 10882 catalog_manager.cc:1383] Generated new cluster ID: 5081e3f243274ea4a928cd3fa225db59
I20260812 06:18:46.045186 10882 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:46.067397 10882 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:46.068765 10882 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:46.076723 10882 catalog_manager.cc:6092] T 00000000000000000000000000000000 P f8df717c1f0741a8a056fba615275b56: Generated new TSK 0
I20260812 06:18:46.077536 10882 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:46.103446 10760 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:46.106079 10895 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:46.106202 10902 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:46.106400 10760 server_base.cc:1061] running on GCE node
W20260812 06:18:46.106469 10896 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:46.106797 10760 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:46.106843 10760 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:46.106864 10760 hybrid_clock.cc:648] HybridClock initialized: now 1786515526106864 us; error 0 us; skew 500 ppm
I20260812 06:18:46.107767 10760 webserver.cc:533] Webserver started at http://127.10.130.1:35133/ using document root <none> and password file <none>
I20260812 06:18:46.107939 10760 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:46.107992 10760 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:46.108067 10760 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:46.108435 10760 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515525954692-10760-0/minicluster-data/ts-0-root/instance:
uuid: "e9429e8680184edebffeb39db65c9da1"
format_stamp: "Formatted at 2026-08-12 06:18:46 on dist-test-slave-6bbx"
I20260812 06:18:46.109860 10760 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:18:46.110781 10908 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:46.110996 10760 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:18:46.111065 10760 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515525954692-10760-0/minicluster-data/ts-0-root
uuid: "e9429e8680184edebffeb39db65c9da1"
format_stamp: "Formatted at 2026-08-12 06:18:46 on dist-test-slave-6bbx"
I20260812 06:18:46.111133 10760 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515525954692-10760-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515525954692-10760-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515525954692-10760-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:46.122613 10760 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:46.123044 10760 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:46.123531 10760 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:46.124791 10760 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:46.124846 10760 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:46.124891 10760 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:46.124920 10760 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:46.131098 10760 rpc_server.cc:307] RPC server started. Bound to: 127.10.130.1:38951
I20260812 06:18:46.131155 11004 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.10.130.1:38951 every 8 connection(s)
I20260812 06:18:46.145210 11008 heartbeater.cc:344] Connected to a master server at 127.10.130.62:37049
I20260812 06:18:46.145488 11008 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:46.146011 11008 heartbeater.cc:507] Master 127.10.130.62:37049 requested a full tablet report, sending...
I20260812 06:18:46.147482 10804 ts_manager.cc:194] Registered new tserver with Master: e9429e8680184edebffeb39db65c9da1 (127.10.130.1:38951)
I20260812 06:18:46.148366 10760 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.016613812s
I20260812 06:18:46.148803 10804 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:39528
I20260812 06:18:46.158188 10804 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:39536:
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:46.172724 10949 tablet_service.cc:1511] Processing CreateTablet for tablet dcf02f50e00346e58f3dc41ef6d778e1 (DEFAULT_TABLE table=heavy-update-compaction-test [id=fcdbfec1ac284f6480da672e6dc5140d]), partition=
I20260812 06:18:46.173198 10949 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet dcf02f50e00346e58f3dc41ef6d778e1. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:46.175472 11022 tablet_bootstrap.cc:492] T dcf02f50e00346e58f3dc41ef6d778e1 P e9429e8680184edebffeb39db65c9da1: Bootstrap starting.
I20260812 06:18:46.176666 11022 tablet_bootstrap.cc:654] T dcf02f50e00346e58f3dc41ef6d778e1 P e9429e8680184edebffeb39db65c9da1: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:46.178115 11022 tablet_bootstrap.cc:492] T dcf02f50e00346e58f3dc41ef6d778e1 P e9429e8680184edebffeb39db65c9da1: No bootstrap required, opened a new log
I20260812 06:18:46.178203 11022 ts_tablet_manager.cc:1403] T dcf02f50e00346e58f3dc41ef6d778e1 P e9429e8680184edebffeb39db65c9da1: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:18:46.178676 11022 raft_consensus.cc:359] T dcf02f50e00346e58f3dc41ef6d778e1 P e9429e8680184edebffeb39db65c9da1 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e9429e8680184edebffeb39db65c9da1" member_type: VOTER last_known_addr { host: "127.10.130.1" port: 38951 } }
I20260812 06:18:46.178779 11022 raft_consensus.cc:385] T dcf02f50e00346e58f3dc41ef6d778e1 P e9429e8680184edebffeb39db65c9da1 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:46.178803 11022 raft_consensus.cc:740] T dcf02f50e00346e58f3dc41ef6d778e1 P e9429e8680184edebffeb39db65c9da1 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: e9429e8680184edebffeb39db65c9da1, State: Initialized, Role: FOLLOWER
I20260812 06:18:46.178937 11022 consensus_queue.cc:260] T dcf02f50e00346e58f3dc41ef6d778e1 P e9429e8680184edebffeb39db65c9da1 [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: "e9429e8680184edebffeb39db65c9da1" member_type: VOTER last_known_addr { host: "127.10.130.1" port: 38951 } }
I20260812 06:18:46.179009 11022 raft_consensus.cc:399] T dcf02f50e00346e58f3dc41ef6d778e1 P e9429e8680184edebffeb39db65c9da1 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:46.179034 11022 raft_consensus.cc:493] T dcf02f50e00346e58f3dc41ef6d778e1 P e9429e8680184edebffeb39db65c9da1 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:46.179081 11022 raft_consensus.cc:3060] T dcf02f50e00346e58f3dc41ef6d778e1 P e9429e8680184edebffeb39db65c9da1 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:46.179925 11022 raft_consensus.cc:515] T dcf02f50e00346e58f3dc41ef6d778e1 P e9429e8680184edebffeb39db65c9da1 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e9429e8680184edebffeb39db65c9da1" member_type: VOTER last_known_addr { host: "127.10.130.1" port: 38951 } }
I20260812 06:18:46.180063 11022 leader_election.cc:304] T dcf02f50e00346e58f3dc41ef6d778e1 P e9429e8680184edebffeb39db65c9da1 [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: e9429e8680184edebffeb39db65c9da1; no voters: 
I20260812 06:18:46.180285 11022 leader_election.cc:290] T dcf02f50e00346e58f3dc41ef6d778e1 P e9429e8680184edebffeb39db65c9da1 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:46.180620 11027 raft_consensus.cc:2804] T dcf02f50e00346e58f3dc41ef6d778e1 P e9429e8680184edebffeb39db65c9da1 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:46.180673 11022 ts_tablet_manager.cc:1434] T dcf02f50e00346e58f3dc41ef6d778e1 P e9429e8680184edebffeb39db65c9da1: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:18:46.181085 11008 heartbeater.cc:499] Master 127.10.130.62:37049 was elected leader, sending a full tablet report...
I20260812 06:18:46.181069 11027 raft_consensus.cc:697] T dcf02f50e00346e58f3dc41ef6d778e1 P e9429e8680184edebffeb39db65c9da1 [term 1 LEADER]: Becoming Leader. State: Replica: e9429e8680184edebffeb39db65c9da1, State: Running, Role: LEADER
I20260812 06:18:46.181497 11027 consensus_queue.cc:237] T dcf02f50e00346e58f3dc41ef6d778e1 P e9429e8680184edebffeb39db65c9da1 [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: "e9429e8680184edebffeb39db65c9da1" member_type: VOTER last_known_addr { host: "127.10.130.1" port: 38951 } }
I20260812 06:18:46.184123 10804 catalog_manager.cc:5719] T dcf02f50e00346e58f3dc41ef6d778e1 P e9429e8680184edebffeb39db65c9da1 reported cstate change: term changed from 0 to 1, leader changed from <none> to e9429e8680184edebffeb39db65c9da1 (127.10.130.1). New cstate: current_term: 1 leader_uuid: "e9429e8680184edebffeb39db65c9da1" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e9429e8680184edebffeb39db65c9da1" member_type: VOTER last_known_addr { host: "127.10.130.1" port: 38951 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:46.249660 10760 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.057s	user 0.024s	sys 0.004s
I20260812 06:18:46.382189 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling FlushMRSOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=19.054940
I20260812 06:18:46.551151 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: FlushMRSOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.169s	user 0.138s	sys 0.020s Metrics: {"bytes_written":12307490,"cfile_init":1,"compiler_manager_pool.queue_time_us":202,"delete_count":0,"dirs.queue_time_us":54,"dirs.run_cpu_time_us":204,"dirs.run_wall_time_us":964,"drs_written":1,"lbm_read_time_us":78,"lbm_reads_lt_1ms":4,"lbm_write_time_us":39312,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":113,"threads_started":1,"update_count":1500}
I20260812 06:18:46.552332 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling LogGCOp(dcf02f50e00346e58f3dc41ef6d778e1): free 20743880 bytes of WAL
I20260812 06:18:46.552697 10916 log_reader.cc:385] T dcf02f50e00346e58f3dc41ef6d778e1: removed 2 log segments from log reader
I20260812 06:18:46.552775 10916 log.cc:1079] T dcf02f50e00346e58f3dc41ef6d778e1 P e9429e8680184edebffeb39db65c9da1: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/dcf02f50e00346e58f3dc41ef6d778e1/wal-000000001 (ops 1-6)
I20260812 06:18:46.552841 10916 log.cc:1079] T dcf02f50e00346e58f3dc41ef6d778e1 P e9429e8680184edebffeb39db65c9da1: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/dcf02f50e00346e58f3dc41ef6d778e1/wal-000000002 (ops 7-11)
I20260812 06:18:46.556540 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: LogGCOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.004s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:18:46.556995 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=2.188937
I20260812 06:18:46.573746 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.017s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5520,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:46.574242 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling UndoDeltaBlockGCOp(dcf02f50e00346e58f3dc41ef6d778e1): 16411395 bytes on disk
I20260812 06:18:46.574787 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: UndoDeltaBlockGCOp(dcf02f50e00346e58f3dc41ef6d778e1) 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:46.575182 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling MajorDeltaCompactionOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=1.000000
I20260812 06:18:46.712796 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: MajorDeltaCompactionOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.137s	user 0.103s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":972,"lbm_read_time_us":7078,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23365,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"thread_start_us":300,"threads_started":5,"update_count":2000}
I20260812 06:18:46.713271 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=10.126437
I20260812 06:18:46.757155 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.044s	user 0.006s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13163,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:46.757709 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=2.188937
I20260812 06:18:46.773171 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5550,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:46.773802 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling MajorDeltaCompactionOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=1.000000
I20260812 06:18:46.893836 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: MajorDeltaCompactionOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.120s	user 0.082s	sys 0.037s 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":178,"lbm_read_time_us":7813,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23650,"lbm_writes_lt_1ms":443,"mutex_wait_us":72,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:46.894415 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=10.126437
I20260812 06:18:46.935510 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.041s	user 0.011s	sys 0.027s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17265,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:46.936038 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=2.188937
I20260812 06:18:46.945807 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.010s	user 0.007s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3565,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:46.946375 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling MajorDeltaCompactionOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=1.000000
I20260812 06:18:47.069885 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: MajorDeltaCompactionOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.123s	user 0.100s	sys 0.020s 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":5186,"lbm_read_time_us":9218,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22799,"lbm_writes_lt_1ms":443,"mutex_wait_us":2334,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:47.070375 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=10.126437
I20260812 06:18:47.117036 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.046s	user 0.020s	sys 0.020s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15482,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:47.117622 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=2.188937
I20260812 06:18:47.129115 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3927,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:47.129601 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling MajorDeltaCompactionOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=1.000000
I20260812 06:18:47.282876 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: MajorDeltaCompactionOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.153s	user 0.090s	sys 0.054s 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":518,"lbm_read_time_us":10203,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25425,"lbm_writes_lt_1ms":443,"mutex_wait_us":280,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":36992,"update_count":2000}
I20260812 06:18:47.283589 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=10.126437
I20260812 06:18:47.325412 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.042s	user 0.011s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12392,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:47.325924 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=2.188937
I20260812 06:18:47.341779 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.016s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5705,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:47.342422 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling MajorDeltaCompactionOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=1.000000
I20260812 06:18:47.466006 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: MajorDeltaCompactionOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.123s	user 0.104s	sys 0.020s 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":315,"lbm_read_time_us":7501,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26048,"lbm_writes_lt_1ms":443,"mutex_wait_us":53,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:47.466579 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=10.126437
I20260812 06:18:47.504886 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.038s	user 0.021s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12400,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:47.505472 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=2.188937
I20260812 06:18:47.517139 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4081,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:47.517567 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling MajorDeltaCompactionOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=1.000000
I20260812 06:18:47.623987 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: MajorDeltaCompactionOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.106s	user 0.078s	sys 0.028s 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":290,"lbm_read_time_us":7485,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20081,"lbm_writes_lt_1ms":443,"mutex_wait_us":21,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":44288,"update_count":2000}
I20260812 06:18:47.625109 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=10.126437
I20260812 06:18:47.657568 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.032s	user 0.017s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13381,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:47.657989 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=2.188937
I20260812 06:18:47.668403 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.010s	user 0.004s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3987,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:47.668870 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling FlushMRSOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=1.000000
I20260812 06:18:47.699433 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: FlushMRSOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.030s	user 0.027s	sys 0.002s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":60,"dirs.run_cpu_time_us":256,"dirs.run_wall_time_us":1305,"drs_written":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1852,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:47.700222 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling LogGCOp(dcf02f50e00346e58f3dc41ef6d778e1): free 112239310 bytes of WAL
I20260812 06:18:47.700443 10916 log_reader.cc:385] T dcf02f50e00346e58f3dc41ef6d778e1: removed 11 log segments from log reader
I20260812 06:18:47.700487 10916 log.cc:1079] T dcf02f50e00346e58f3dc41ef6d778e1 P e9429e8680184edebffeb39db65c9da1: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/dcf02f50e00346e58f3dc41ef6d778e1/wal-000000003 (ops 12-16)
I20260812 06:18:47.700516 10916 log.cc:1079] T dcf02f50e00346e58f3dc41ef6d778e1 P e9429e8680184edebffeb39db65c9da1: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/dcf02f50e00346e58f3dc41ef6d778e1/wal-000000004 (ops 17-21)
I20260812 06:18:47.700549 10916 log.cc:1079] T dcf02f50e00346e58f3dc41ef6d778e1 P e9429e8680184edebffeb39db65c9da1: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/dcf02f50e00346e58f3dc41ef6d778e1/wal-000000005 (ops 22-26)
I20260812 06:18:47.700574 10916 log.cc:1079] T dcf02f50e00346e58f3dc41ef6d778e1 P e9429e8680184edebffeb39db65c9da1: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/dcf02f50e00346e58f3dc41ef6d778e1/wal-000000006 (ops 27-31)
I20260812 06:18:47.700606 10916 log.cc:1079] T dcf02f50e00346e58f3dc41ef6d778e1 P e9429e8680184edebffeb39db65c9da1: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/dcf02f50e00346e58f3dc41ef6d778e1/wal-000000007 (ops 32-36)
I20260812 06:18:47.700634 10916 log.cc:1079] T dcf02f50e00346e58f3dc41ef6d778e1 P e9429e8680184edebffeb39db65c9da1: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/dcf02f50e00346e58f3dc41ef6d778e1/wal-000000008 (ops 37-41)
I20260812 06:18:47.700665 10916 log.cc:1079] T dcf02f50e00346e58f3dc41ef6d778e1 P e9429e8680184edebffeb39db65c9da1: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/dcf02f50e00346e58f3dc41ef6d778e1/wal-000000009 (ops 42-46)
I20260812 06:18:47.700695 10916 log.cc:1079] T dcf02f50e00346e58f3dc41ef6d778e1 P e9429e8680184edebffeb39db65c9da1: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/dcf02f50e00346e58f3dc41ef6d778e1/wal-000000010 (ops 47-50)
I20260812 06:18:47.700726 10916 log.cc:1079] T dcf02f50e00346e58f3dc41ef6d778e1 P e9429e8680184edebffeb39db65c9da1: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/dcf02f50e00346e58f3dc41ef6d778e1/wal-000000011 (ops 51-55)
I20260812 06:18:47.700757 10916 log.cc:1079] T dcf02f50e00346e58f3dc41ef6d778e1 P e9429e8680184edebffeb39db65c9da1: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/dcf02f50e00346e58f3dc41ef6d778e1/wal-000000012 (ops 56-60)
I20260812 06:18:47.700788 10916 log.cc:1079] T dcf02f50e00346e58f3dc41ef6d778e1 P e9429e8680184edebffeb39db65c9da1: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/dcf02f50e00346e58f3dc41ef6d778e1/wal-000000013 (ops 61-65)
I20260812 06:18:47.719416 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: LogGCOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.019s	user 0.000s	sys 0.015s Metrics: {}
I20260812 06:18:47.719874 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling UndoDeltaBlockGCOp(dcf02f50e00346e58f3dc41ef6d778e1): 447 bytes on disk
I20260812 06:18:47.720278 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: UndoDeltaBlockGCOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4}
I20260812 06:18:47.720721 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=3.181125
I20260812 06:18:47.736220 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.015s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":3926,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:47.736699 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=2.188937
I20260812 06:18:47.750200 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.013s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4724,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:47.750782 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling MajorDeltaCompactionOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=1.000000
I20260812 06:18:47.923103 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: MajorDeltaCompactionOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.172s	user 0.126s	sys 0.036s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877329,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":177,"lbm_read_time_us":10836,"lbm_reads_lt_1ms":674,"lbm_write_time_us":32921,"lbm_writes_lt_1ms":643,"mutex_wait_us":44,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3328,"thread_start_us":76,"threads_started":1,"update_count":3000}
I20260812 06:18:47.923612 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=14.095187
I20260812 06:18:47.978235 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.054s	user 0.026s	sys 0.016s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":19391,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:47.978700 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=2.188937
I20260812 06:18:47.988763 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3716,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:47.989159 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling MajorDeltaCompactionOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=1.000000
I20260812 06:18:48.145179 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: MajorDeltaCompactionOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.156s	user 0.097s	sys 0.055s 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":153,"lbm_read_time_us":10103,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29700,"lbm_writes_lt_1ms":543,"mutex_wait_us":45,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":116608,"update_count":2500}
I20260812 06:18:48.146060 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=11.118625
I20260812 06:18:48.179960 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.034s	user 0.030s	sys 0.004s Metrics: {"bytes_written":12594666,"delete_count":0,"lbm_write_time_us":14010,"lbm_writes_lt_1ms":310,"reinsert_count":0,"update_count":1535}
I20260812 06:18:48.180729 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=2.188937
I20260812 06:18:48.198267 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.017s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3815483,"delete_count":0,"lbm_write_time_us":4083,"lbm_writes_lt_1ms":96,"reinsert_count":0,"update_count":465}
I20260812 06:18:48.198745 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling MajorDeltaCompactionOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=1.000000
I20260812 06:18:48.341872 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: MajorDeltaCompactionOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.143s	user 0.089s	sys 0.045s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":519,"lbm_read_time_us":8041,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23209,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:48.342456 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=14.095187
I20260812 06:18:48.386166 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.044s	user 0.025s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18853,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:48.386654 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=2.188937
I20260812 06:18:48.408313 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.021s	user 0.005s	sys 0.016s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5647,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:48.408751 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling MajorDeltaCompactionOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=1.000000
I20260812 06:18:48.573930 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: MajorDeltaCompactionOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.165s	user 0.126s	sys 0.036s 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":889,"lbm_read_time_us":11443,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25956,"lbm_writes_lt_1ms":543,"mutex_wait_us":1,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:48.574515 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=11.118625
I20260812 06:18:48.601677 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.027s	user 0.017s	sys 0.008s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":11375,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:48.602283 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=2.188937
I20260812 06:18:48.617470 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4825,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:48.617983 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling MajorDeltaCompactionOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=1.000000
I20260812 06:18:48.740783 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: MajorDeltaCompactionOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.123s	user 0.107s	sys 0.015s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":626,"lbm_read_time_us":8707,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23321,"lbm_writes_lt_1ms":443,"mutex_wait_us":79,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:18:48.741360 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=11.118625
I20260812 06:18:48.777483 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.036s	user 0.022s	sys 0.012s Metrics: {"bytes_written":12553635,"delete_count":0,"lbm_write_time_us":15331,"lbm_writes_lt_1ms":309,"reinsert_count":0,"update_count":1530}
I20260812 06:18:48.778077 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=2.188937
I20260812 06:18:48.790548 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3856508,"delete_count":0,"lbm_write_time_us":4212,"lbm_writes_lt_1ms":97,"reinsert_count":0,"update_count":470}
I20260812 06:18:48.791116 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling MajorDeltaCompactionOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=1.000000
I20260812 06:18:48.896754 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: MajorDeltaCompactionOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.105s	user 0.073s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672271,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":551,"lbm_read_time_us":6889,"lbm_reads_lt_1ms":464,"lbm_write_time_us":19580,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:18:48.897334 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=10.126437
I20260812 06:18:48.930576 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.033s	user 0.022s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13197,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:48.931212 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=2.188937
I20260812 06:18:48.946528 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.015s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5604,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:48.947211 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling FlushMRSOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=1.000000
I20260812 06:18:48.972970 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: FlushMRSOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.026s	user 0.024s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":51,"dirs.run_cpu_time_us":193,"dirs.run_wall_time_us":1362,"drs_written":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1324,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:48.973774 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling LogGCOp(dcf02f50e00346e58f3dc41ef6d778e1): free 112692391 bytes of WAL
I20260812 06:18:48.974054 10916 log_reader.cc:385] T dcf02f50e00346e58f3dc41ef6d778e1: removed 11 log segments from log reader
I20260812 06:18:48.974109 10916 log.cc:1079] T dcf02f50e00346e58f3dc41ef6d778e1 P e9429e8680184edebffeb39db65c9da1: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/dcf02f50e00346e58f3dc41ef6d778e1/wal-000000014 (ops 66-70)
I20260812 06:18:48.974159 10916 log.cc:1079] T dcf02f50e00346e58f3dc41ef6d778e1 P e9429e8680184edebffeb39db65c9da1: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/dcf02f50e00346e58f3dc41ef6d778e1/wal-000000015 (ops 71-75)
I20260812 06:18:48.974190 10916 log.cc:1079] T dcf02f50e00346e58f3dc41ef6d778e1 P e9429e8680184edebffeb39db65c9da1: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/dcf02f50e00346e58f3dc41ef6d778e1/wal-000000016 (ops 76-80)
I20260812 06:18:48.974215 10916 log.cc:1079] T dcf02f50e00346e58f3dc41ef6d778e1 P e9429e8680184edebffeb39db65c9da1: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/dcf02f50e00346e58f3dc41ef6d778e1/wal-000000017 (ops 81-85)
I20260812 06:18:48.974244 10916 log.cc:1079] T dcf02f50e00346e58f3dc41ef6d778e1 P e9429e8680184edebffeb39db65c9da1: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/dcf02f50e00346e58f3dc41ef6d778e1/wal-000000018 (ops 86-90)
I20260812 06:18:48.974275 10916 log.cc:1079] T dcf02f50e00346e58f3dc41ef6d778e1 P e9429e8680184edebffeb39db65c9da1: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/dcf02f50e00346e58f3dc41ef6d778e1/wal-000000019 (ops 91-95)
I20260812 06:18:48.974305 10916 log.cc:1079] T dcf02f50e00346e58f3dc41ef6d778e1 P e9429e8680184edebffeb39db65c9da1: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/dcf02f50e00346e58f3dc41ef6d778e1/wal-000000020 (ops 96-100)
I20260812 06:18:48.974334 10916 log.cc:1079] T dcf02f50e00346e58f3dc41ef6d778e1 P e9429e8680184edebffeb39db65c9da1: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/dcf02f50e00346e58f3dc41ef6d778e1/wal-000000021 (ops 101-105)
I20260812 06:18:48.974364 10916 log.cc:1079] T dcf02f50e00346e58f3dc41ef6d778e1 P e9429e8680184edebffeb39db65c9da1: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/dcf02f50e00346e58f3dc41ef6d778e1/wal-000000022 (ops 106-110)
I20260812 06:18:48.974395 10916 log.cc:1079] T dcf02f50e00346e58f3dc41ef6d778e1 P e9429e8680184edebffeb39db65c9da1: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/dcf02f50e00346e58f3dc41ef6d778e1/wal-000000023 (ops 111-115)
I20260812 06:18:48.974423 10916 log.cc:1079] T dcf02f50e00346e58f3dc41ef6d778e1 P e9429e8680184edebffeb39db65c9da1: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/dcf02f50e00346e58f3dc41ef6d778e1/wal-000000024 (ops 116-120)
I20260812 06:18:48.994815 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: LogGCOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.021s	user 0.003s	sys 0.015s Metrics: {}
I20260812 06:18:48.995271 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling UndoDeltaBlockGCOp(dcf02f50e00346e58f3dc41ef6d778e1): 447 bytes on disk
I20260812 06:18:48.995831 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: UndoDeltaBlockGCOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":71,"lbm_reads_lt_1ms":4}
I20260812 06:18:48.996353 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=3.181125
I20260812 06:18:49.011029 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.015s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4045,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:49.011524 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=2.188937
I20260812 06:18:49.021231 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.009s	user 0.007s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3362,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:49.021703 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling MajorDeltaCompactionOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=1.000000
I20260812 06:18:49.183909 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: MajorDeltaCompactionOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.162s	user 0.130s	sys 0.027s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877329,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1091,"lbm_read_time_us":11067,"lbm_reads_lt_1ms":674,"lbm_write_time_us":31103,"lbm_writes_lt_1ms":643,"mutex_wait_us":47,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12928,"thread_start_us":90,"threads_started":1,"update_count":3000}
I20260812 06:18:49.184778 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=14.095187
I20260812 06:18:49.235571 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.051s	user 0.015s	sys 0.028s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19806,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:49.236173 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=2.188937
I20260812 06:18:49.246855 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3947,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:49.247514 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling MajorDeltaCompactionOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=1.000000
I20260812 06:18:49.403889 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: MajorDeltaCompactionOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.156s	user 0.110s	sys 0.041s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":3691,"lbm_read_time_us":11626,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27667,"lbm_writes_lt_1ms":543,"mutex_wait_us":3050,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3456,"update_count":2500}
I20260812 06:18:49.404779 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=11.118625
I20260812 06:18:49.431823 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.027s	user 0.019s	sys 0.008s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":11473,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:49.432422 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=2.188937
I20260812 06:18:49.448619 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.016s	user 0.008s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5301,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:49.449172 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling MajorDeltaCompactionOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=1.000000
I20260812 06:18:49.579864 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: MajorDeltaCompactionOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.131s	user 0.079s	sys 0.050s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":937,"lbm_read_time_us":8277,"lbm_reads_lt_1ms":468,"lbm_write_time_us":21816,"lbm_writes_lt_1ms":443,"mutex_wait_us":633,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2000}
I20260812 06:18:49.580437 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=11.118625
I20260812 06:18:49.614359 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.034s	user 0.018s	sys 0.013s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14078,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:49.614991 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=2.188937
I20260812 06:18:49.640498 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.025s	user 0.004s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4557,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:49.641009 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=2.188937
I20260812 06:18:49.662935 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.022s	user 0.004s	sys 0.014s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5329,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:49.663570 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling MajorDeltaCompactionOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=1.000000
I20260812 06:18:49.826411 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: MajorDeltaCompactionOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.163s	user 0.116s	sys 0.044s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774798,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":188,"lbm_read_time_us":11869,"lbm_reads_lt_1ms":573,"lbm_write_time_us":27884,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2500}
I20260812 06:18:49.827067 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=10.126437
I20260812 06:18:49.856226 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.029s	user 0.025s	sys 0.003s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12452,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:49.856714 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=2.188937
I20260812 06:18:49.870241 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.013s	user 0.008s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4956,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:49.870746 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling MajorDeltaCompactionOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=1.000000
I20260812 06:18:49.995004 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: MajorDeltaCompactionOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.124s	user 0.097s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":3045,"lbm_read_time_us":7435,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23055,"lbm_writes_lt_1ms":443,"mutex_wait_us":2313,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:18:49.995831 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=10.126437
I20260812 06:18:50.027081 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.031s	user 0.019s	sys 0.009s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12949,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:50.027779 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=2.188937
I20260812 06:18:50.038883 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4024,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:50.039487 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling MajorDeltaCompactionOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=1.000000
I20260812 06:18:50.164377 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: MajorDeltaCompactionOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.125s	user 0.102s	sys 0.020s 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":726,"lbm_read_time_us":9272,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21876,"lbm_writes_lt_1ms":443,"mutex_wait_us":60,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":2000}
I20260812 06:18:50.164929 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=10.126437
I20260812 06:18:50.204648 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.040s	user 0.022s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14397,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:50.205189 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=2.188937
I20260812 06:18:50.220341 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.015s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5380,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:50.221000 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling FlushMRSOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=1.000000
I20260812 06:18:50.248428 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: FlushMRSOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.027s	user 0.025s	sys 0.000s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":69,"dirs.run_cpu_time_us":231,"dirs.run_wall_time_us":1370,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1406,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:50.249126 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling LogGCOp(dcf02f50e00346e58f3dc41ef6d778e1): free 124257465 bytes of WAL
I20260812 06:18:50.249356 10916 log_reader.cc:385] T dcf02f50e00346e58f3dc41ef6d778e1: removed 12 log segments from log reader
I20260812 06:18:50.249402 10916 log.cc:1079] T dcf02f50e00346e58f3dc41ef6d778e1 P e9429e8680184edebffeb39db65c9da1: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/dcf02f50e00346e58f3dc41ef6d778e1/wal-000000025 (ops 121-125)
I20260812 06:18:50.249432 10916 log.cc:1079] T dcf02f50e00346e58f3dc41ef6d778e1 P e9429e8680184edebffeb39db65c9da1: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/dcf02f50e00346e58f3dc41ef6d778e1/wal-000000026 (ops 126-130)
I20260812 06:18:50.249465 10916 log.cc:1079] T dcf02f50e00346e58f3dc41ef6d778e1 P e9429e8680184edebffeb39db65c9da1: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/dcf02f50e00346e58f3dc41ef6d778e1/wal-000000027 (ops 131-135)
I20260812 06:18:50.249495 10916 log.cc:1079] T dcf02f50e00346e58f3dc41ef6d778e1 P e9429e8680184edebffeb39db65c9da1: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/dcf02f50e00346e58f3dc41ef6d778e1/wal-000000028 (ops 136-140)
I20260812 06:18:50.249526 10916 log.cc:1079] T dcf02f50e00346e58f3dc41ef6d778e1 P e9429e8680184edebffeb39db65c9da1: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/dcf02f50e00346e58f3dc41ef6d778e1/wal-000000029 (ops 141-145)
I20260812 06:18:50.249557 10916 log.cc:1079] T dcf02f50e00346e58f3dc41ef6d778e1 P e9429e8680184edebffeb39db65c9da1: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/dcf02f50e00346e58f3dc41ef6d778e1/wal-000000030 (ops 146-150)
I20260812 06:18:50.249588 10916 log.cc:1079] T dcf02f50e00346e58f3dc41ef6d778e1 P e9429e8680184edebffeb39db65c9da1: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/dcf02f50e00346e58f3dc41ef6d778e1/wal-000000031 (ops 151-154)
I20260812 06:18:50.249620 10916 log.cc:1079] T dcf02f50e00346e58f3dc41ef6d778e1 P e9429e8680184edebffeb39db65c9da1: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/dcf02f50e00346e58f3dc41ef6d778e1/wal-000000032 (ops 155-159)
I20260812 06:18:50.249651 10916 log.cc:1079] T dcf02f50e00346e58f3dc41ef6d778e1 P e9429e8680184edebffeb39db65c9da1: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/dcf02f50e00346e58f3dc41ef6d778e1/wal-000000033 (ops 160-164)
I20260812 06:18:50.249682 10916 log.cc:1079] T dcf02f50e00346e58f3dc41ef6d778e1 P e9429e8680184edebffeb39db65c9da1: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/dcf02f50e00346e58f3dc41ef6d778e1/wal-000000034 (ops 165-169)
I20260812 06:18:50.249712 10916 log.cc:1079] T dcf02f50e00346e58f3dc41ef6d778e1 P e9429e8680184edebffeb39db65c9da1: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/dcf02f50e00346e58f3dc41ef6d778e1/wal-000000035 (ops 170-174)
I20260812 06:18:50.249745 10916 log.cc:1079] T dcf02f50e00346e58f3dc41ef6d778e1 P e9429e8680184edebffeb39db65c9da1: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/dcf02f50e00346e58f3dc41ef6d778e1/wal-000000036 (ops 175-179)
I20260812 06:18:50.272655 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: LogGCOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.023s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:18:50.273074 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=3.181125
I20260812 06:18:50.286724 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.013s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":4041,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:50.287179 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=2.188937
I20260812 06:18:50.301326 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.014s	user 0.007s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4928,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:50.301885 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling UndoDeltaBlockGCOp(dcf02f50e00346e58f3dc41ef6d778e1): 447 bytes on disk
I20260812 06:18:50.302353 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: UndoDeltaBlockGCOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4}
I20260812 06:18:50.303017 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling MajorDeltaCompactionOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=1.000000
I20260812 06:18:50.476887 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: MajorDeltaCompactionOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.174s	user 0.121s	sys 0.052s 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":906,"lbm_read_time_us":11915,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34676,"lbm_writes_lt_1ms":643,"mutex_wait_us":273,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1792,"thread_start_us":78,"threads_started":1,"update_count":3000}
I20260812 06:18:50.477373 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=14.095187
I20260812 06:18:50.532944 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.055s	user 0.030s	sys 0.024s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":25438,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:50.533537 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=2.188937
I20260812 06:18:50.546291 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.013s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4514,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:50.547051 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling MajorDeltaCompactionOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=1.000000
I20260812 06:18:50.704056 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: MajorDeltaCompactionOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.157s	user 0.116s	sys 0.032s 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":978,"lbm_read_time_us":8685,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30832,"lbm_writes_lt_1ms":543,"mutex_wait_us":392,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5760,"update_count":2500}
I20260812 06:18:50.704699 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=14.095187
I20260812 06:18:50.746917 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: FlushDeltaMemStoresOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.042s	user 0.015s	sys 0.021s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":17162,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:50.747578 11010 maintenance_manager.cc:419] P e9429e8680184edebffeb39db65c9da1: Scheduling MajorDeltaCompactionOp(dcf02f50e00346e58f3dc41ef6d778e1): perf score=1.000000
I20260812 06:18:50.767921 10760 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.518s	user 1.697s	sys 0.083s
I20260812 06:18:50.834343 10760 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.066s	user 0.001s	sys 0.000s
I20260812 06:18:50.835075 10760 tablet_server.cc:179] TabletServer@127.10.130.1:0 shutting down...
I20260812 06:18:50.872982 10916 maintenance_manager.cc:643] P e9429e8680184edebffeb39db65c9da1: MajorDeltaCompactionOp(dcf02f50e00346e58f3dc41ef6d778e1) complete. Timing: real 0.125s	user 0.094s	sys 0.030s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672160,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":362,"lbm_read_time_us":9258,"lbm_reads_lt_1ms":463,"lbm_write_time_us":19799,"lbm_writes_lt_1ms":443,"mutex_wait_us":1,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":20864,"update_count":2000}
I20260812 06:18:50.873641 10760 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:50.874060 10760 tablet_replica.cc:333] T dcf02f50e00346e58f3dc41ef6d778e1 P e9429e8680184edebffeb39db65c9da1: stopping tablet replica
I20260812 06:18:50.874329 10760 raft_consensus.cc:2243] T dcf02f50e00346e58f3dc41ef6d778e1 P e9429e8680184edebffeb39db65c9da1 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:50.874569 10760 raft_consensus.cc:2272] T dcf02f50e00346e58f3dc41ef6d778e1 P e9429e8680184edebffeb39db65c9da1 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:50.891604 10760 tablet_server.cc:196] TabletServer@127.10.130.1:0 shutdown complete.
I20260812 06:18:50.915601 10760 master.cc:562] Master@127.10.130.62:37049 shutting down...
I20260812 06:18:50.919088 10760 raft_consensus.cc:2243] T 00000000000000000000000000000000 P f8df717c1f0741a8a056fba615275b56 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:50.919299 10760 raft_consensus.cc:2272] T 00000000000000000000000000000000 P f8df717c1f0741a8a056fba615275b56 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:50.919378 10760 tablet_replica.cc:333] T 00000000000000000000000000000000 P f8df717c1f0741a8a056fba615275b56: stopping tablet replica
I20260812 06:18:50.931629 10760 master.cc:584] Master@127.10.130.62:37049 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5043 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:51.008885 10760 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.10.130.62:38657
I20260812 06:18:51.009270 10760 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:51.011159 11053 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:51.011174 11057 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:51.011350 11054 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:51.011469 10760 server_base.cc:1061] running on GCE node
I20260812 06:18:51.011648 10760 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:51.011724 10760 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:51.011754 10760 hybrid_clock.cc:648] HybridClock initialized: now 1786515531011753 us; error 0 us; skew 500 ppm
I20260812 06:18:51.012593 10760 webserver.cc:533] Webserver started at http://127.10.130.62:43907/ using document root <none> and password file <none>
I20260812 06:18:51.012754 10760 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:51.012817 10760 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:51.012897 10760 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:51.013295 10760 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515525954692-10760-0/minicluster-data/master-0-root/instance:
uuid: "42bf7eaa853642479afb17b52aafffd6"
format_stamp: "Formatted at 2026-08-12 06:18:51 on dist-test-slave-6bbx"
I20260812 06:18:51.014798 10760 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:51.015764 11066 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:51.016011 10760 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:51.016083 10760 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515525954692-10760-0/minicluster-data/master-0-root
uuid: "42bf7eaa853642479afb17b52aafffd6"
format_stamp: "Formatted at 2026-08-12 06:18:51 on dist-test-slave-6bbx"
I20260812 06:18:51.016162 10760 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515525954692-10760-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515525954692-10760-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515525954692-10760-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:51.026798 10760 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:51.027246 10760 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:51.031275 10760 rpc_server.cc:307] RPC server started. Bound to: 127.10.130.62:38657
I20260812 06:18:51.044317 11151 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:51.044329 11149 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.10.130.62:38657 every 8 connection(s)
I20260812 06:18:51.046640 11151 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 42bf7eaa853642479afb17b52aafffd6: Bootstrap starting.
I20260812 06:18:51.047631 11151 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 42bf7eaa853642479afb17b52aafffd6: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:51.048903 11151 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 42bf7eaa853642479afb17b52aafffd6: No bootstrap required, opened a new log
I20260812 06:18:51.049404 11151 raft_consensus.cc:359] T 00000000000000000000000000000000 P 42bf7eaa853642479afb17b52aafffd6 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "42bf7eaa853642479afb17b52aafffd6" member_type: VOTER }
I20260812 06:18:51.049505 11151 raft_consensus.cc:385] T 00000000000000000000000000000000 P 42bf7eaa853642479afb17b52aafffd6 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:51.049535 11151 raft_consensus.cc:740] T 00000000000000000000000000000000 P 42bf7eaa853642479afb17b52aafffd6 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 42bf7eaa853642479afb17b52aafffd6, State: Initialized, Role: FOLLOWER
I20260812 06:18:51.049690 11151 consensus_queue.cc:260] T 00000000000000000000000000000000 P 42bf7eaa853642479afb17b52aafffd6 [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: "42bf7eaa853642479afb17b52aafffd6" member_type: VOTER }
I20260812 06:18:51.049777 11151 raft_consensus.cc:399] T 00000000000000000000000000000000 P 42bf7eaa853642479afb17b52aafffd6 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:51.049815 11151 raft_consensus.cc:493] T 00000000000000000000000000000000 P 42bf7eaa853642479afb17b52aafffd6 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:51.049865 11151 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 42bf7eaa853642479afb17b52aafffd6 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:51.050688 11151 raft_consensus.cc:515] T 00000000000000000000000000000000 P 42bf7eaa853642479afb17b52aafffd6 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "42bf7eaa853642479afb17b52aafffd6" member_type: VOTER }
I20260812 06:18:51.050835 11151 leader_election.cc:304] T 00000000000000000000000000000000 P 42bf7eaa853642479afb17b52aafffd6 [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: 42bf7eaa853642479afb17b52aafffd6; no voters: 
I20260812 06:18:51.051040 11151 leader_election.cc:290] T 00000000000000000000000000000000 P 42bf7eaa853642479afb17b52aafffd6 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:51.051203 11154 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 42bf7eaa853642479afb17b52aafffd6 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:51.051414 11154 raft_consensus.cc:697] T 00000000000000000000000000000000 P 42bf7eaa853642479afb17b52aafffd6 [term 1 LEADER]: Becoming Leader. State: Replica: 42bf7eaa853642479afb17b52aafffd6, State: Running, Role: LEADER
I20260812 06:18:51.051532 11151 sys_catalog.cc:565] T 00000000000000000000000000000000 P 42bf7eaa853642479afb17b52aafffd6 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:51.051561 11154 consensus_queue.cc:237] T 00000000000000000000000000000000 P 42bf7eaa853642479afb17b52aafffd6 [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: "42bf7eaa853642479afb17b52aafffd6" member_type: VOTER }
I20260812 06:18:51.052066 11158 sys_catalog.cc:455] T 00000000000000000000000000000000 P 42bf7eaa853642479afb17b52aafffd6 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 42bf7eaa853642479afb17b52aafffd6. Latest consensus state: current_term: 1 leader_uuid: "42bf7eaa853642479afb17b52aafffd6" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "42bf7eaa853642479afb17b52aafffd6" member_type: VOTER } }
I20260812 06:18:51.052042 11157 sys_catalog.cc:455] T 00000000000000000000000000000000 P 42bf7eaa853642479afb17b52aafffd6 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "42bf7eaa853642479afb17b52aafffd6" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "42bf7eaa853642479afb17b52aafffd6" member_type: VOTER } }
I20260812 06:18:51.052151 11158 sys_catalog.cc:458] T 00000000000000000000000000000000 P 42bf7eaa853642479afb17b52aafffd6 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:51.052161 11157 sys_catalog.cc:458] T 00000000000000000000000000000000 P 42bf7eaa853642479afb17b52aafffd6 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:51.052512 11166 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:51.053570 11166 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:51.053742 10760 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:51.055738 11166 catalog_manager.cc:1383] Generated new cluster ID: 8bc437399fcd4f40adb483533073b0a1
I20260812 06:18:51.055853 11166 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:51.065578 11166 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:51.066155 11166 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:51.072809 11166 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 42bf7eaa853642479afb17b52aafffd6: Generated new TSK 0
I20260812 06:18:51.072980 11166 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:51.086135 10760 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:51.088128 11184 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:51.088155 11183 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:51.088241 10760 server_base.cc:1061] running on GCE node
W20260812 06:18:51.088287 11188 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:51.088567 10760 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:51.088610 10760 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:51.088625 10760 hybrid_clock.cc:648] HybridClock initialized: now 1786515531088626 us; error 0 us; skew 500 ppm
I20260812 06:18:51.089416 10760 webserver.cc:533] Webserver started at http://127.10.130.1:37533/ using document root <none> and password file <none>
I20260812 06:18:51.089565 10760 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:51.089612 10760 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:51.089669 10760 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:51.090016 10760 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515525954692-10760-0/minicluster-data/ts-0-root/instance:
uuid: "58da9a5cff1b472ba9c4c4c3aa57e65a"
format_stamp: "Formatted at 2026-08-12 06:18:51 on dist-test-slave-6bbx"
I20260812 06:18:51.091379 10760 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:51.092314 11194 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:51.092516 10760 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.000s
I20260812 06:18:51.092579 10760 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515525954692-10760-0/minicluster-data/ts-0-root
uuid: "58da9a5cff1b472ba9c4c4c3aa57e65a"
format_stamp: "Formatted at 2026-08-12 06:18:51 on dist-test-slave-6bbx"
I20260812 06:18:51.092636 10760 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515525954692-10760-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515525954692-10760-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515525954692-10760-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:51.104810 10760 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:51.105171 10760 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:51.105448 10760 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:51.105909 10760 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:51.105948 10760 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:51.105985 10760 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:51.106014 10760 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:51.110142 10760 rpc_server.cc:307] RPC server started. Bound to: 127.10.130.1:32935
I20260812 06:18:51.110165 11292 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.10.130.1:32935 every 8 connection(s)
I20260812 06:18:51.114688 11294 heartbeater.cc:344] Connected to a master server at 127.10.130.62:38657
I20260812 06:18:51.114792 11294 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:51.114986 11294 heartbeater.cc:507] Master 127.10.130.62:38657 requested a full tablet report, sending...
I20260812 06:18:51.115559 11093 ts_manager.cc:194] Registered new tserver with Master: 58da9a5cff1b472ba9c4c4c3aa57e65a (127.10.130.1:32935)
I20260812 06:18:51.116048 10760 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.005521734s
I20260812 06:18:51.116593 11093 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:37148
I20260812 06:18:51.122809 11093 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:37150:
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:51.131222 11236 tablet_service.cc:1511] Processing CreateTablet for tablet 607ea063e9d54d6db6eee55052b2a3b1 (DEFAULT_TABLE table=heavy-update-compaction-test [id=7f4094f016a644e08833af8d444c4826]), partition=
I20260812 06:18:51.131572 11236 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 607ea063e9d54d6db6eee55052b2a3b1. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:51.133849 11314 tablet_bootstrap.cc:492] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a: Bootstrap starting.
I20260812 06:18:51.134799 11314 tablet_bootstrap.cc:654] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:51.135962 11314 tablet_bootstrap.cc:492] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a: No bootstrap required, opened a new log
I20260812 06:18:51.136052 11314 ts_tablet_manager.cc:1403] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:51.136479 11314 raft_consensus.cc:359] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "58da9a5cff1b472ba9c4c4c3aa57e65a" member_type: VOTER last_known_addr { host: "127.10.130.1" port: 32935 } }
I20260812 06:18:51.136605 11314 raft_consensus.cc:385] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:51.136634 11314 raft_consensus.cc:740] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 58da9a5cff1b472ba9c4c4c3aa57e65a, State: Initialized, Role: FOLLOWER
I20260812 06:18:51.136790 11314 consensus_queue.cc:260] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a [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: "58da9a5cff1b472ba9c4c4c3aa57e65a" member_type: VOTER last_known_addr { host: "127.10.130.1" port: 32935 } }
I20260812 06:18:51.136899 11314 raft_consensus.cc:399] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:51.136946 11314 raft_consensus.cc:493] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:51.136998 11314 raft_consensus.cc:3060] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:51.137800 11314 raft_consensus.cc:515] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "58da9a5cff1b472ba9c4c4c3aa57e65a" member_type: VOTER last_known_addr { host: "127.10.130.1" port: 32935 } }
I20260812 06:18:51.137933 11314 leader_election.cc:304] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a [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: 58da9a5cff1b472ba9c4c4c3aa57e65a; no voters: 
I20260812 06:18:51.138139 11314 leader_election.cc:290] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:51.138255 11316 raft_consensus.cc:2804] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:51.138486 11294 heartbeater.cc:499] Master 127.10.130.62:38657 was elected leader, sending a full tablet report...
I20260812 06:18:51.138443 11314 ts_tablet_manager.cc:1434] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:18:51.138461 11316 raft_consensus.cc:697] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a [term 1 LEADER]: Becoming Leader. State: Replica: 58da9a5cff1b472ba9c4c4c3aa57e65a, State: Running, Role: LEADER
I20260812 06:18:51.138664 11316 consensus_queue.cc:237] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a [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: "58da9a5cff1b472ba9c4c4c3aa57e65a" member_type: VOTER last_known_addr { host: "127.10.130.1" port: 32935 } }
I20260812 06:18:51.140093 11093 catalog_manager.cc:5719] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a reported cstate change: term changed from 0 to 1, leader changed from <none> to 58da9a5cff1b472ba9c4c4c3aa57e65a (127.10.130.1). New cstate: current_term: 1 leader_uuid: "58da9a5cff1b472ba9c4c4c3aa57e65a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "58da9a5cff1b472ba9c4c4c3aa57e65a" member_type: VOTER last_known_addr { host: "127.10.130.1" port: 32935 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:51.198321 10760 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.051s	user 0.017s	sys 0.005s
I20260812 06:18:51.360965 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling FlushMRSOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=23.023690
I20260812 06:18:51.514249 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: FlushMRSOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.153s	user 0.118s	sys 0.032s Metrics: {"bytes_written":12307491,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":75,"dirs.run_cpu_time_us":197,"dirs.run_wall_time_us":963,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":41074,"lbm_writes_lt_1ms":857,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":1500}
I20260812 06:18:51.514976 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling LogGCOp(607ea063e9d54d6db6eee55052b2a3b1): free 20743880 bytes of WAL
I20260812 06:18:51.515200 11202 log_reader.cc:385] T 607ea063e9d54d6db6eee55052b2a3b1: removed 2 log segments from log reader
I20260812 06:18:51.515255 11202 log.cc:1079] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/607ea063e9d54d6db6eee55052b2a3b1/wal-000000001 (ops 1-6)
I20260812 06:18:51.515285 11202 log.cc:1079] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/607ea063e9d54d6db6eee55052b2a3b1/wal-000000002 (ops 7-11)
I20260812 06:18:51.518992 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: LogGCOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.004s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:18:51.519392 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling UndoDeltaBlockGCOp(607ea063e9d54d6db6eee55052b2a3b1): 20513816 bytes on disk
I20260812 06:18:51.519879 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: UndoDeltaBlockGCOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":89,"lbm_reads_lt_1ms":4}
I20260812 06:18:51.520306 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=2.188937
I20260812 06:18:51.537959 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.018s	user 0.005s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5717,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:51.538511 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling MajorDeltaCompactionOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=1.000000
I20260812 06:18:51.706547 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: MajorDeltaCompactionOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.168s	user 0.103s	sys 0.060s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":527,"lbm_read_time_us":11244,"lbm_reads_lt_1ms":460,"lbm_write_time_us":25616,"lbm_writes_lt_1ms":443,"mutex_wait_us":33,"peak_mem_usage":50689328,"reinsert_count":0,"thread_start_us":287,"threads_started":5,"update_count":2000}
I20260812 06:18:51.707019 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=14.095187
I20260812 06:18:51.755074 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.048s	user 0.032s	sys 0.008s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18987,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:51.755571 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=2.188937
I20260812 06:18:51.765563 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3580,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:51.766204 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling MajorDeltaCompactionOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=1.000000
I20260812 06:18:51.918041 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: MajorDeltaCompactionOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.152s	user 0.116s	sys 0.032s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":193,"lbm_read_time_us":11517,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26588,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4352,"update_count":2500}
I20260812 06:18:51.918684 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=11.118625
I20260812 06:18:51.952677 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.034s	user 0.026s	sys 0.007s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14117,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:51.953248 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=2.188937
I20260812 06:18:51.979552 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.026s	user 0.011s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":7606,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":92,"reinsert_count":0,"update_count":450}
I20260812 06:18:51.980082 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=2.188937
I20260812 06:18:51.990291 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3772,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:51.990921 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling MajorDeltaCompactionOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=1.000000
I20260812 06:18:52.136482 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: MajorDeltaCompactionOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.145s	user 0.119s	sys 0.023s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815794,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":878,"lbm_read_time_us":9930,"lbm_reads_lt_1ms":573,"lbm_write_time_us":28169,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":542,"mutex_wait_us":42,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":19840,"update_count":2500}
I20260812 06:18:52.137291 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=11.118625
I20260812 06:18:52.172127 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.035s	user 0.023s	sys 0.011s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":14382,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:52.172729 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=2.188937
I20260812 06:18:52.193089 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.020s	user 0.007s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4502,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:52.193671 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling MajorDeltaCompactionOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=1.000000
I20260812 06:18:52.321388 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: MajorDeltaCompactionOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.128s	user 0.099s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713264,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":108,"lbm_read_time_us":8820,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24498,"lbm_writes_lt_1ms":443,"mutex_wait_us":32,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8960,"update_count":2000}
I20260812 06:18:52.322389 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=10.126437
I20260812 06:18:52.365590 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.043s	user 0.023s	sys 0.018s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13959,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":1500}
I20260812 06:18:52.366258 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=2.188937
I20260812 06:18:52.377127 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3873,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:52.377919 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling MajorDeltaCompactionOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=1.000000
I20260812 06:18:52.528070 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: MajorDeltaCompactionOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.150s	user 0.110s	sys 0.039s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":254,"lbm_read_time_us":10250,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25338,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2000}
I20260812 06:18:52.528685 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=10.126437
I20260812 06:18:52.572461 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.044s	user 0.013s	sys 0.020s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":14519,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:52.572939 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=2.188937
I20260812 06:18:52.583204 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3766,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:52.583817 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling MajorDeltaCompactionOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=1.000000
I20260812 06:18:52.700062 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: MajorDeltaCompactionOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.116s	user 0.095s	sys 0.021s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713274,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":732,"lbm_read_time_us":7837,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21145,"lbm_writes_lt_1ms":443,"mutex_wait_us":303,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5632,"update_count":2000}
I20260812 06:18:52.700645 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=10.126437
I20260812 06:18:52.737666 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.037s	user 0.020s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14857,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:52.738288 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=2.188937
I20260812 06:18:52.748641 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.010s	user 0.000s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3759,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:52.749182 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling FlushMRSOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=1.000000
I20260812 06:18:52.776746 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: FlushMRSOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.027s	user 0.022s	sys 0.003s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":93,"dirs.run_cpu_time_us":255,"dirs.run_wall_time_us":1554,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1467,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:18:52.777489 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling LogGCOp(607ea063e9d54d6db6eee55052b2a3b1): free 124710290 bytes of WAL
I20260812 06:18:52.777781 11202 log_reader.cc:385] T 607ea063e9d54d6db6eee55052b2a3b1: removed 12 log segments from log reader
I20260812 06:18:52.777848 11202 log.cc:1079] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/607ea063e9d54d6db6eee55052b2a3b1/wal-000000003 (ops 12-16)
I20260812 06:18:52.777901 11202 log.cc:1079] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/607ea063e9d54d6db6eee55052b2a3b1/wal-000000004 (ops 17-21)
I20260812 06:18:52.777933 11202 log.cc:1079] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/607ea063e9d54d6db6eee55052b2a3b1/wal-000000005 (ops 22-26)
I20260812 06:18:52.777956 11202 log.cc:1079] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/607ea063e9d54d6db6eee55052b2a3b1/wal-000000006 (ops 27-31)
I20260812 06:18:52.777983 11202 log.cc:1079] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/607ea063e9d54d6db6eee55052b2a3b1/wal-000000007 (ops 32-36)
I20260812 06:18:52.778015 11202 log.cc:1079] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/607ea063e9d54d6db6eee55052b2a3b1/wal-000000008 (ops 37-41)
I20260812 06:18:52.778047 11202 log.cc:1079] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/607ea063e9d54d6db6eee55052b2a3b1/wal-000000009 (ops 42-46)
I20260812 06:18:52.778076 11202 log.cc:1079] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/607ea063e9d54d6db6eee55052b2a3b1/wal-000000010 (ops 47-51)
I20260812 06:18:52.778103 11202 log.cc:1079] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/607ea063e9d54d6db6eee55052b2a3b1/wal-000000011 (ops 52-56)
I20260812 06:18:52.778132 11202 log.cc:1079] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/607ea063e9d54d6db6eee55052b2a3b1/wal-000000012 (ops 57-61)
I20260812 06:18:52.778163 11202 log.cc:1079] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/607ea063e9d54d6db6eee55052b2a3b1/wal-000000013 (ops 62-66)
I20260812 06:18:52.778194 11202 log.cc:1079] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/607ea063e9d54d6db6eee55052b2a3b1/wal-000000014 (ops 67-71)
I20260812 06:18:52.804958 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: LogGCOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.027s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:18:52.805460 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling UndoDeltaBlockGCOp(607ea063e9d54d6db6eee55052b2a3b1): 472 bytes on disk
I20260812 06:18:52.805902 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: UndoDeltaBlockGCOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4}
I20260812 06:18:52.806427 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=2.188937
I20260812 06:18:52.819981 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.013s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3966,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:52.820554 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=2.188937
I20260812 06:18:52.831106 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3787,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:52.831700 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling MajorDeltaCompactionOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=1.000000
I20260812 06:18:53.002427 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: MajorDeltaCompactionOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.170s	user 0.113s	sys 0.057s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918333,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1027,"lbm_read_time_us":11632,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34994,"lbm_writes_lt_1ms":643,"mutex_wait_us":317,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":10752,"thread_start_us":80,"threads_started":1,"update_count":3000}
I20260812 06:18:53.003010 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=14.095187
I20260812 06:18:53.056970 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.054s	user 0.042s	sys 0.008s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22922,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:53.057418 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=2.188937
I20260812 06:18:53.067920 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3793,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:53.068528 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling MajorDeltaCompactionOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=1.000000
I20260812 06:18:53.222465 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: MajorDeltaCompactionOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.154s	user 0.116s	sys 0.025s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":623,"lbm_read_time_us":10254,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26435,"lbm_writes_lt_1ms":543,"mutex_wait_us":68,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2500}
I20260812 06:18:53.222990 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=14.095187
I20260812 06:18:53.267248 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.044s	user 0.003s	sys 0.032s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":16302,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:53.267961 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=2.188937
I20260812 06:18:53.279003 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.011s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3844,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:53.279606 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling MajorDeltaCompactionOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=1.000000
I20260812 06:18:53.428481 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: MajorDeltaCompactionOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.149s	user 0.112s	sys 0.037s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":697,"lbm_read_time_us":9225,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30152,"lbm_writes_lt_1ms":543,"mutex_wait_us":319,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4992,"update_count":2500}
I20260812 06:18:53.429069 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=10.126437
I20260812 06:18:53.462718 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.033s	user 0.014s	sys 0.012s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":12291,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:53.463171 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=2.188937
I20260812 06:18:53.477208 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5371,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:53.477885 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling MajorDeltaCompactionOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=1.000000
I20260812 06:18:53.604992 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: MajorDeltaCompactionOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.127s	user 0.101s	sys 0.025s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713275,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1010,"lbm_read_time_us":8900,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22360,"lbm_writes_lt_1ms":443,"mutex_wait_us":332,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2000}
I20260812 06:18:53.605578 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=10.126437
I20260812 06:18:53.652501 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.047s	user 0.031s	sys 0.003s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":11754,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:53.653182 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=2.188937
I20260812 06:18:53.663491 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3866,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:53.663966 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling MajorDeltaCompactionOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=1.000000
I20260812 06:18:53.798873 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: MajorDeltaCompactionOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.135s	user 0.099s	sys 0.035s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":957,"lbm_read_time_us":10263,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21183,"lbm_writes_lt_1ms":443,"mutex_wait_us":316,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":45056,"update_count":2000}
I20260812 06:18:53.799443 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=10.126437
I20260812 06:18:53.836934 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.037s	user 0.020s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12223,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:53.837474 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=2.188937
I20260812 06:18:53.847568 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3780,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:53.848129 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling MajorDeltaCompactionOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=1.000000
I20260812 06:18:53.968539 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: MajorDeltaCompactionOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.120s	user 0.092s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":208,"lbm_read_time_us":8101,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24286,"lbm_writes_lt_1ms":443,"mutex_wait_us":43,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":18944,"update_count":2000}
I20260812 06:18:53.969087 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=10.126437
I20260812 06:18:54.010028 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.041s	user 0.018s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14012,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:54.010541 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=2.188937
I20260812 06:18:54.020677 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3783,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:54.021185 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling FlushMRSOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=1.000000
I20260812 06:18:54.049093 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: FlushMRSOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.028s	user 0.022s	sys 0.004s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":53,"dirs.run_cpu_time_us":195,"dirs.run_wall_time_us":1417,"drs_written":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1559,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:54.049701 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling LogGCOp(607ea063e9d54d6db6eee55052b2a3b1): free 112692371 bytes of WAL
I20260812 06:18:54.049908 11202 log_reader.cc:385] T 607ea063e9d54d6db6eee55052b2a3b1: removed 11 log segments from log reader
I20260812 06:18:54.049952 11202 log.cc:1079] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/607ea063e9d54d6db6eee55052b2a3b1/wal-000000015 (ops 72-76)
I20260812 06:18:54.049978 11202 log.cc:1079] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/607ea063e9d54d6db6eee55052b2a3b1/wal-000000016 (ops 77-81)
I20260812 06:18:54.050010 11202 log.cc:1079] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/607ea063e9d54d6db6eee55052b2a3b1/wal-000000017 (ops 82-86)
I20260812 06:18:54.050041 11202 log.cc:1079] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/607ea063e9d54d6db6eee55052b2a3b1/wal-000000018 (ops 87-91)
I20260812 06:18:54.050073 11202 log.cc:1079] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/607ea063e9d54d6db6eee55052b2a3b1/wal-000000019 (ops 92-96)
I20260812 06:18:54.050104 11202 log.cc:1079] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/607ea063e9d54d6db6eee55052b2a3b1/wal-000000020 (ops 97-101)
I20260812 06:18:54.050134 11202 log.cc:1079] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/607ea063e9d54d6db6eee55052b2a3b1/wal-000000021 (ops 102-106)
I20260812 06:18:54.050166 11202 log.cc:1079] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/607ea063e9d54d6db6eee55052b2a3b1/wal-000000022 (ops 107-111)
I20260812 06:18:54.050196 11202 log.cc:1079] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/607ea063e9d54d6db6eee55052b2a3b1/wal-000000023 (ops 112-116)
I20260812 06:18:54.050227 11202 log.cc:1079] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/607ea063e9d54d6db6eee55052b2a3b1/wal-000000024 (ops 117-121)
I20260812 06:18:54.050258 11202 log.cc:1079] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/607ea063e9d54d6db6eee55052b2a3b1/wal-000000025 (ops 122-126)
I20260812 06:18:54.069038 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: LogGCOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.019s	user 0.003s	sys 0.015s Metrics: {}
I20260812 06:18:54.069447 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=3.181125
I20260812 06:18:54.089423 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.020s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4410,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:54.089915 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=2.188937
I20260812 06:18:54.099354 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3426,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:54.099881 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling UndoDeltaBlockGCOp(607ea063e9d54d6db6eee55052b2a3b1): 447 bytes on disk
I20260812 06:18:54.100313 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: UndoDeltaBlockGCOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:18:54.100818 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling MajorDeltaCompactionOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=1.000000
I20260812 06:18:54.279932 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: MajorDeltaCompactionOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.179s	user 0.145s	sys 0.028s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918325,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":2132,"lbm_read_time_us":12580,"lbm_reads_lt_1ms":674,"lbm_write_time_us":36000,"lbm_writes_lt_1ms":643,"mutex_wait_us":1538,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":8960,"thread_start_us":74,"threads_started":1,"update_count":3000}
I20260812 06:18:54.280889 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=14.095187
I20260812 06:18:54.326602 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.045s	user 0.026s	sys 0.017s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":19924,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:54.327046 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=2.188937
I20260812 06:18:54.337201 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3849,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:54.337706 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling MajorDeltaCompactionOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=1.000000
I20260812 06:18:54.475862 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: MajorDeltaCompactionOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.138s	user 0.114s	sys 0.024s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":175,"lbm_read_time_us":10160,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27991,"lbm_writes_lt_1ms":543,"mutex_wait_us":27,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14976,"update_count":2500}
I20260812 06:18:54.476558 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=10.126437
I20260812 06:18:54.506098 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.029s	user 0.013s	sys 0.014s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":12551,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:54.506596 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=2.188937
I20260812 06:18:54.519099 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.012s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4533,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:54.519811 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling MajorDeltaCompactionOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=1.000000
I20260812 06:18:54.637192 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: MajorDeltaCompactionOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.117s	user 0.096s	sys 0.021s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713274,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":610,"lbm_read_time_us":7464,"lbm_reads_lt_1ms":464,"lbm_write_time_us":21827,"lbm_writes_lt_1ms":443,"mutex_wait_us":292,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":18304,"update_count":2000}
I20260812 06:18:54.637792 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=10.126437
I20260812 06:18:54.679786 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.042s	user 0.020s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14090,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:54.680320 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=2.188937
I20260812 06:18:54.690749 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3572,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:54.691534 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling MajorDeltaCompactionOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=1.000000
I20260812 06:18:54.813572 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: MajorDeltaCompactionOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.122s	user 0.097s	sys 0.025s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":246,"lbm_read_time_us":8240,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23013,"lbm_writes_lt_1ms":443,"mutex_wait_us":31,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3456,"update_count":2000}
I20260812 06:18:54.814117 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=10.126437
I20260812 06:18:54.865429 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.051s	user 0.029s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15770,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:54.865980 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=2.188937
I20260812 06:18:54.876202 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3754,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:54.876636 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling MajorDeltaCompactionOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=1.000000
I20260812 06:18:55.025463 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: MajorDeltaCompactionOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.149s	user 0.104s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":272,"lbm_read_time_us":10890,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23605,"lbm_writes_lt_1ms":443,"mutex_wait_us":20,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":18432,"update_count":2000}
I20260812 06:18:55.026094 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=10.126437
I20260812 06:18:55.063409 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.037s	user 0.020s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13140,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:55.063963 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=2.188937
I20260812 06:18:55.075110 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.011s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3929,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:55.075758 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling MajorDeltaCompactionOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=1.000000
I20260812 06:18:55.198987 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: MajorDeltaCompactionOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.123s	user 0.100s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":337,"lbm_read_time_us":8555,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23855,"lbm_writes_lt_1ms":443,"mutex_wait_us":1,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2000}
I20260812 06:18:55.199626 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=10.126437
I20260812 06:18:55.239728 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.040s	user 0.023s	sys 0.005s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12956,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:55.240363 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=2.188937
I20260812 06:18:55.251082 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.011s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3798,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:55.251715 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling MajorDeltaCompactionOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=1.000000
I20260812 06:18:55.371464 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: MajorDeltaCompactionOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.120s	user 0.078s	sys 0.041s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":837,"lbm_read_time_us":8255,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23866,"lbm_writes_lt_1ms":443,"mutex_wait_us":276,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:18:55.372125 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=10.126437
I20260812 06:18:55.419521 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.047s	user 0.027s	sys 0.010s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13774,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:55.420171 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=2.188937
I20260812 06:18:55.430998 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4040,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:55.431512 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling FlushMRSOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=1.000000
I20260812 06:18:55.470752 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: FlushMRSOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.039s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":64,"dirs.run_cpu_time_us":224,"dirs.run_wall_time_us":1414,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1506,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:18:55.471473 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling LogGCOp(607ea063e9d54d6db6eee55052b2a3b1): free 136275445 bytes of WAL
I20260812 06:18:55.471736 11202 log_reader.cc:385] T 607ea063e9d54d6db6eee55052b2a3b1: removed 13 log segments from log reader
I20260812 06:18:55.471792 11202 log.cc:1079] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/607ea063e9d54d6db6eee55052b2a3b1/wal-000000026 (ops 127-131)
I20260812 06:18:55.471823 11202 log.cc:1079] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/607ea063e9d54d6db6eee55052b2a3b1/wal-000000027 (ops 132-136)
I20260812 06:18:55.471854 11202 log.cc:1079] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/607ea063e9d54d6db6eee55052b2a3b1/wal-000000028 (ops 137-141)
I20260812 06:18:55.471884 11202 log.cc:1079] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/607ea063e9d54d6db6eee55052b2a3b1/wal-000000029 (ops 142-146)
I20260812 06:18:55.471917 11202 log.cc:1079] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/607ea063e9d54d6db6eee55052b2a3b1/wal-000000030 (ops 147-150)
I20260812 06:18:55.471948 11202 log.cc:1079] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/607ea063e9d54d6db6eee55052b2a3b1/wal-000000031 (ops 151-155)
I20260812 06:18:55.471980 11202 log.cc:1079] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/607ea063e9d54d6db6eee55052b2a3b1/wal-000000032 (ops 156-160)
I20260812 06:18:55.472011 11202 log.cc:1079] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/607ea063e9d54d6db6eee55052b2a3b1/wal-000000033 (ops 161-165)
I20260812 06:18:55.472043 11202 log.cc:1079] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/607ea063e9d54d6db6eee55052b2a3b1/wal-000000034 (ops 166-170)
I20260812 06:18:55.472074 11202 log.cc:1079] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/607ea063e9d54d6db6eee55052b2a3b1/wal-000000035 (ops 171-175)
I20260812 06:18:55.472107 11202 log.cc:1079] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/607ea063e9d54d6db6eee55052b2a3b1/wal-000000036 (ops 176-180)
I20260812 06:18:55.472139 11202 log.cc:1079] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/607ea063e9d54d6db6eee55052b2a3b1/wal-000000037 (ops 181-185)
I20260812 06:18:55.472172 11202 log.cc:1079] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a: Deleting log segment in path: /tmp/dist-test-taskQLfDOE/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515525954692-10760-0/minicluster-data/ts-0-root/wals/607ea063e9d54d6db6eee55052b2a3b1/wal-000000038 (ops 186-190)
I20260812 06:18:55.496399 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: LogGCOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.025s	user 0.001s	sys 0.023s Metrics: {}
I20260812 06:18:55.496802 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=3.181125
I20260812 06:18:55.513904 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.017s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4169,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:55.514396 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=2.188937
I20260812 06:18:55.523962 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.009s	user 0.001s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3377,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:55.524487 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling MajorDeltaCompactionOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=1.000000
I20260812 06:18:55.707376 10760 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.509s	user 1.716s	sys 0.124s
I20260812 06:18:55.718295 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: MajorDeltaCompactionOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.194s	user 0.113s	sys 0.081s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918324,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":505,"lbm_read_time_us":12158,"lbm_reads_lt_1ms":674,"lbm_write_time_us":32265,"lbm_writes_lt_1ms":643,"mutex_wait_us":83,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12160,"thread_start_us":103,"threads_started":1,"update_count":3000}
I20260812 06:18:55.720221 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling UndoDeltaBlockGCOp(607ea063e9d54d6db6eee55052b2a3b1): 482 bytes on disk
I20260812 06:18:55.720614 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: UndoDeltaBlockGCOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":43,"lbm_reads_lt_1ms":4}
I20260812 06:18:55.721171 11295 maintenance_manager.cc:419] P 58da9a5cff1b472ba9c4c4c3aa57e65a: Scheduling FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1): perf score=14.095187
I20260812 06:18:55.750485 10760 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.043s	user 0.001s	sys 0.000s
I20260812 06:18:55.751056 10760 tablet_server.cc:179] TabletServer@127.10.130.1:0 shutting down...
I20260812 06:18:55.760296 11202 maintenance_manager.cc:643] P 58da9a5cff1b472ba9c4c4c3aa57e65a: FlushDeltaMemStoresOp(607ea063e9d54d6db6eee55052b2a3b1) complete. Timing: real 0.039s	user 0.030s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17302,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:55.760833 10760 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:55.761034 10760 tablet_replica.cc:333] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a: stopping tablet replica
I20260812 06:18:55.761164 10760 raft_consensus.cc:2243] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:55.761319 10760 raft_consensus.cc:2272] T 607ea063e9d54d6db6eee55052b2a3b1 P 58da9a5cff1b472ba9c4c4c3aa57e65a [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:55.764981 10760 tablet_server.cc:196] TabletServer@127.10.130.1:0 shutdown complete.
I20260812 06:18:55.768217 10760 master.cc:562] Master@127.10.130.62:38657 shutting down...
I20260812 06:18:55.771071 10760 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 42bf7eaa853642479afb17b52aafffd6 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:55.771235 10760 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 42bf7eaa853642479afb17b52aafffd6 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:55.771289 10760 tablet_replica.cc:333] T 00000000000000000000000000000000 P 42bf7eaa853642479afb17b52aafffd6: stopping tablet replica
I20260812 06:18:55.783808 10760 master.cc:584] Master@127.10.130.62:38657 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (4847 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (9892 ms total)

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