[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:19:13.424338 18703 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.18.67.254:46723
I20260812 06:19:13.425417 18703 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:19:13.426056 18703 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:13.433593 18708 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:13.433662 18709 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:13.433941 18711 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:13.434029 18703 server_base.cc:1061] running on GCE node
I20260812 06:19:13.434579 18703 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:13.434713 18703 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:13.434762 18703 hybrid_clock.cc:648] HybridClock initialized: now 1786515553434760 us; error 0 us; skew 500 ppm
I20260812 06:19:13.436914 18703 webserver.cc:533] Webserver started at http://127.18.67.254:43833/ using document root <none> and password file <none>
I20260812 06:19:13.437542 18703 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:13.437634 18703 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:13.437887 18703 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:13.439672 18703 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553413118-18703-0/minicluster-data/master-0-root/instance:
uuid: "4d5010c855044ac18d086255be48467a"
format_stamp: "Formatted at 2026-08-12 06:19:13 on dist-test-slave-27sr"
I20260812 06:19:13.443502 18703 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:19:13.445976 18717 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:13.447135 18703 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:13.447309 18703 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553413118-18703-0/minicluster-data/master-0-root
uuid: "4d5010c855044ac18d086255be48467a"
format_stamp: "Formatted at 2026-08-12 06:19:13 on dist-test-slave-27sr"
I20260812 06:19:13.447424 18703 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553413118-18703-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553413118-18703-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553413118-18703-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:13.461385 18703 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:13.462073 18703 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:19:13.462265 18703 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:13.470741 18703 rpc_server.cc:307] RPC server started. Bound to: 127.18.67.254:46723
I20260812 06:19:13.470767 18780 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.18.67.254:46723 every 8 connection(s)
I20260812 06:19:13.473169 18781 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:13.478818 18781 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 4d5010c855044ac18d086255be48467a: Bootstrap starting.
I20260812 06:19:13.481340 18781 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 4d5010c855044ac18d086255be48467a: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:13.482278 18781 log.cc:826] T 00000000000000000000000000000000 P 4d5010c855044ac18d086255be48467a: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:13.484000 18781 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 4d5010c855044ac18d086255be48467a: No bootstrap required, opened a new log
I20260812 06:19:13.486898 18781 raft_consensus.cc:359] T 00000000000000000000000000000000 P 4d5010c855044ac18d086255be48467a [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4d5010c855044ac18d086255be48467a" member_type: VOTER }
I20260812 06:19:13.487074 18781 raft_consensus.cc:385] T 00000000000000000000000000000000 P 4d5010c855044ac18d086255be48467a [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:13.487118 18781 raft_consensus.cc:740] T 00000000000000000000000000000000 P 4d5010c855044ac18d086255be48467a [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 4d5010c855044ac18d086255be48467a, State: Initialized, Role: FOLLOWER
I20260812 06:19:13.487645 18781 consensus_queue.cc:260] T 00000000000000000000000000000000 P 4d5010c855044ac18d086255be48467a [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: "4d5010c855044ac18d086255be48467a" member_type: VOTER }
I20260812 06:19:13.487782 18781 raft_consensus.cc:399] T 00000000000000000000000000000000 P 4d5010c855044ac18d086255be48467a [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:13.487829 18781 raft_consensus.cc:493] T 00000000000000000000000000000000 P 4d5010c855044ac18d086255be48467a [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:13.487987 18781 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 4d5010c855044ac18d086255be48467a [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:13.488775 18781 raft_consensus.cc:515] T 00000000000000000000000000000000 P 4d5010c855044ac18d086255be48467a [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4d5010c855044ac18d086255be48467a" member_type: VOTER }
I20260812 06:19:13.489163 18781 leader_election.cc:304] T 00000000000000000000000000000000 P 4d5010c855044ac18d086255be48467a [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: 4d5010c855044ac18d086255be48467a; no voters: 
I20260812 06:19:13.489456 18781 leader_election.cc:290] T 00000000000000000000000000000000 P 4d5010c855044ac18d086255be48467a [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:13.489607 18784 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 4d5010c855044ac18d086255be48467a [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:13.489872 18784 raft_consensus.cc:697] T 00000000000000000000000000000000 P 4d5010c855044ac18d086255be48467a [term 1 LEADER]: Becoming Leader. State: Replica: 4d5010c855044ac18d086255be48467a, State: Running, Role: LEADER
I20260812 06:19:13.490295 18784 consensus_queue.cc:237] T 00000000000000000000000000000000 P 4d5010c855044ac18d086255be48467a [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: "4d5010c855044ac18d086255be48467a" member_type: VOTER }
I20260812 06:19:13.490571 18781 sys_catalog.cc:565] T 00000000000000000000000000000000 P 4d5010c855044ac18d086255be48467a [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:13.492370 18786 sys_catalog.cc:455] T 00000000000000000000000000000000 P 4d5010c855044ac18d086255be48467a [sys.catalog]: SysCatalogTable state changed. Reason: New leader 4d5010c855044ac18d086255be48467a. Latest consensus state: current_term: 1 leader_uuid: "4d5010c855044ac18d086255be48467a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4d5010c855044ac18d086255be48467a" member_type: VOTER } }
I20260812 06:19:13.492380 18785 sys_catalog.cc:455] T 00000000000000000000000000000000 P 4d5010c855044ac18d086255be48467a [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "4d5010c855044ac18d086255be48467a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4d5010c855044ac18d086255be48467a" member_type: VOTER } }
I20260812 06:19:13.492523 18786 sys_catalog.cc:458] T 00000000000000000000000000000000 P 4d5010c855044ac18d086255be48467a [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:13.492578 18785 sys_catalog.cc:458] T 00000000000000000000000000000000 P 4d5010c855044ac18d086255be48467a [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:13.492970 18703 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:19:13.494889 18800 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 4d5010c855044ac18d086255be48467a: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:19:13.494949 18800 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:19:13.495028 18798 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:13.495743 18798 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:13.500173 18798 catalog_manager.cc:1383] Generated new cluster ID: 81d61e6ef11e40b1afb8be3509a765f2
I20260812 06:19:13.500244 18798 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:13.513978 18798 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:13.514899 18798 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:13.525038 18798 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 4d5010c855044ac18d086255be48467a: Generated new TSK 0
I20260812 06:19:13.525714 18798 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:13.558051 18703 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:13.560963 18808 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:13.560987 18806 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:13.561053 18805 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:13.561362 18703 server_base.cc:1061] running on GCE node
I20260812 06:19:13.561529 18703 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:13.561584 18703 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:13.561618 18703 hybrid_clock.cc:648] HybridClock initialized: now 1786515553561618 us; error 0 us; skew 500 ppm
I20260812 06:19:13.562597 18703 webserver.cc:533] Webserver started at http://127.18.67.193:36101/ using document root <none> and password file <none>
I20260812 06:19:13.562791 18703 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:13.562862 18703 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:13.562944 18703 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:13.563361 18703 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553413118-18703-0/minicluster-data/ts-0-root/instance:
uuid: "b4a9316feec2499eb0034318ec732763"
format_stamp: "Formatted at 2026-08-12 06:19:13 on dist-test-slave-27sr"
I20260812 06:19:13.565101 18703 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:19:13.566171 18816 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:13.566427 18703 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:13.566499 18703 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553413118-18703-0/minicluster-data/ts-0-root
uuid: "b4a9316feec2499eb0034318ec732763"
format_stamp: "Formatted at 2026-08-12 06:19:13 on dist-test-slave-27sr"
I20260812 06:19:13.566589 18703 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553413118-18703-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553413118-18703-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553413118-18703-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:13.573804 18703 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:13.574291 18703 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:13.574820 18703 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:13.575681 18703 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:13.575740 18703 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:13.575811 18703 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:13.575845 18703 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:13.582842 18703 rpc_server.cc:307] RPC server started. Bound to: 127.18.67.193:40671
I20260812 06:19:13.582875 18892 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.18.67.193:40671 every 8 connection(s)
I20260812 06:19:13.597193 18893 heartbeater.cc:344] Connected to a master server at 127.18.67.254:46723
I20260812 06:19:13.597460 18893 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:13.597985 18893 heartbeater.cc:507] Master 127.18.67.254:46723 requested a full tablet report, sending...
I20260812 06:19:13.599534 18738 ts_manager.cc:194] Registered new tserver with Master: b4a9316feec2499eb0034318ec732763 (127.18.67.193:40671)
I20260812 06:19:13.600122 18703 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.016620227s
I20260812 06:19:13.601135 18738 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:43048
I20260812 06:19:13.609604 18738 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:43062:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:13.623147 18851 tablet_service.cc:1511] Processing CreateTablet for tablet 500775f955d7465e9b094bee98a5a59d (DEFAULT_TABLE table=heavy-update-compaction-test [id=feada8605ea8432f8f4ad7c3467da9b3]), partition=
I20260812 06:19:13.623658 18851 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 500775f955d7465e9b094bee98a5a59d. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:13.625993 18905 tablet_bootstrap.cc:492] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763: Bootstrap starting.
I20260812 06:19:13.627097 18905 tablet_bootstrap.cc:654] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:13.628360 18905 tablet_bootstrap.cc:492] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763: No bootstrap required, opened a new log
I20260812 06:19:13.628481 18905 ts_tablet_manager.cc:1403] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:19:13.628985 18905 raft_consensus.cc:359] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b4a9316feec2499eb0034318ec732763" member_type: VOTER last_known_addr { host: "127.18.67.193" port: 40671 } }
I20260812 06:19:13.629114 18905 raft_consensus.cc:385] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:13.629163 18905 raft_consensus.cc:740] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: b4a9316feec2499eb0034318ec732763, State: Initialized, Role: FOLLOWER
I20260812 06:19:13.629310 18905 consensus_queue.cc:260] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763 [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: "b4a9316feec2499eb0034318ec732763" member_type: VOTER last_known_addr { host: "127.18.67.193" port: 40671 } }
I20260812 06:19:13.629426 18905 raft_consensus.cc:399] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:13.629477 18905 raft_consensus.cc:493] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:13.629532 18905 raft_consensus.cc:3060] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:13.630256 18905 raft_consensus.cc:515] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b4a9316feec2499eb0034318ec732763" member_type: VOTER last_known_addr { host: "127.18.67.193" port: 40671 } }
I20260812 06:19:13.630412 18905 leader_election.cc:304] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763 [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: b4a9316feec2499eb0034318ec732763; no voters: 
I20260812 06:19:13.630652 18905 leader_election.cc:290] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:13.630770 18907 raft_consensus.cc:2804] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:13.630990 18907 raft_consensus.cc:697] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763 [term 1 LEADER]: Becoming Leader. State: Replica: b4a9316feec2499eb0034318ec732763, State: Running, Role: LEADER
I20260812 06:19:13.631177 18905 ts_tablet_manager.cc:1434] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:19:13.631165 18907 consensus_queue.cc:237] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763 [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: "b4a9316feec2499eb0034318ec732763" member_type: VOTER last_known_addr { host: "127.18.67.193" port: 40671 } }
I20260812 06:19:13.631611 18893 heartbeater.cc:499] Master 127.18.67.254:46723 was elected leader, sending a full tablet report...
I20260812 06:19:13.634052 18738 catalog_manager.cc:5719] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763 reported cstate change: term changed from 0 to 1, leader changed from <none> to b4a9316feec2499eb0034318ec732763 (127.18.67.193). New cstate: current_term: 1 leader_uuid: "b4a9316feec2499eb0034318ec732763" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b4a9316feec2499eb0034318ec732763" member_type: VOTER last_known_addr { host: "127.18.67.193" port: 40671 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:13.703625 18703 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.059s	user 0.024s	sys 0.004s
I20260812 06:19:13.834239 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling FlushMRSOp(500775f955d7465e9b094bee98a5a59d): perf score=15.086190
I20260812 06:19:14.000370 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: FlushMRSOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.166s	user 0.130s	sys 0.028s Metrics: {"bytes_written":12307492,"cfile_init":1,"compiler_manager_pool.queue_time_us":255,"delete_count":0,"dirs.queue_time_us":83,"dirs.run_cpu_time_us":249,"dirs.run_wall_time_us":1169,"drs_written":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4,"lbm_write_time_us":39512,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"thread_start_us":127,"threads_started":1,"update_count":1500}
I20260812 06:19:14.001587 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling LogGCOp(500775f955d7465e9b094bee98a5a59d): free 11976772 bytes of WAL
I20260812 06:19:14.001929 18822 log_reader.cc:385] T 500775f955d7465e9b094bee98a5a59d: removed 1 log segments from log reader
I20260812 06:19:14.002010 18822 log.cc:1079] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/500775f955d7465e9b094bee98a5a59d/wal-000000001 (ops 1-6)
I20260812 06:19:14.004565 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: LogGCOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.003s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:19:14.004875 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling UndoDeltaBlockGCOp(500775f955d7465e9b094bee98a5a59d): 12308958 bytes on disk
I20260812 06:19:14.005410 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: UndoDeltaBlockGCOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4}
I20260812 06:19:14.005829 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d): perf score=2.188937
I20260812 06:19:14.019868 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5190,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:14.020354 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling MajorDeltaCompactionOp(500775f955d7465e9b094bee98a5a59d): perf score=1.000000
I20260812 06:19:14.154660 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: MajorDeltaCompactionOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.134s	user 0.113s	sys 0.021s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631314,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":924,"lbm_read_time_us":7278,"lbm_reads_lt_1ms":460,"lbm_write_time_us":24826,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":356,"threads_started":5,"update_count":2000}
I20260812 06:19:14.155435 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d): perf score=10.126437
I20260812 06:19:14.205458 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.050s	user 0.035s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19400,"lbm_writes_lt_1ms":303,"mutex_wait_us":2,"reinsert_count":0,"update_count":1500}
I20260812 06:19:14.205956 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d): perf score=2.188937
I20260812 06:19:14.218369 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4409,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:14.218887 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling MajorDeltaCompactionOp(500775f955d7465e9b094bee98a5a59d): perf score=1.000000
I20260812 06:19:14.360383 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: MajorDeltaCompactionOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.141s	user 0.122s	sys 0.019s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":835,"lbm_read_time_us":9992,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29483,"lbm_writes_lt_1ms":443,"mutex_wait_us":43,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:19:14.360978 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d): perf score=10.126437
I20260812 06:19:14.407245 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.046s	user 0.020s	sys 0.013s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15669,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:14.407809 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d): perf score=2.188937
I20260812 06:19:14.421027 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4605,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:14.421612 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling MajorDeltaCompactionOp(500775f955d7465e9b094bee98a5a59d): perf score=1.000000
I20260812 06:19:14.541999 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: MajorDeltaCompactionOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.120s	user 0.091s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1569,"lbm_read_time_us":8848,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23899,"lbm_writes_lt_1ms":443,"mutex_wait_us":713,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:14.542665 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d): perf score=10.126437
I20260812 06:19:14.589877 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.047s	user 0.030s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16912,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:14.590457 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d): perf score=2.188937
I20260812 06:19:14.602010 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4359,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:14.602453 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling MajorDeltaCompactionOp(500775f955d7465e9b094bee98a5a59d): perf score=1.000000
I20260812 06:19:14.749378 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: MajorDeltaCompactionOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.147s	user 0.084s	sys 0.062s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":284,"lbm_read_time_us":10697,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22608,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:14.749992 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d): perf score=10.126437
I20260812 06:19:14.794965 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.045s	user 0.026s	sys 0.009s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16526,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:14.795410 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d): perf score=2.188937
I20260812 06:19:14.806233 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4220,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:14.806702 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling MajorDeltaCompactionOp(500775f955d7465e9b094bee98a5a59d): perf score=1.000000
I20260812 06:19:14.932921 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: MajorDeltaCompactionOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.126s	user 0.110s	sys 0.015s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":364,"lbm_read_time_us":9436,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22855,"lbm_writes_lt_1ms":443,"mutex_wait_us":72,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":27904,"update_count":2000}
I20260812 06:19:14.938709 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d): perf score=10.126437
I20260812 06:19:14.974560 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.035s	user 0.025s	sys 0.004s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13456,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:14.975198 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d): perf score=2.188937
I20260812 06:19:14.987272 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4593,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:14.987982 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling MajorDeltaCompactionOp(500775f955d7465e9b094bee98a5a59d): perf score=1.000000
I20260812 06:19:15.122524 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: MajorDeltaCompactionOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.134s	user 0.108s	sys 0.025s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1192,"lbm_read_time_us":10086,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24562,"lbm_writes_lt_1ms":443,"mutex_wait_us":366,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":22400,"update_count":2000}
I20260812 06:19:15.123486 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d): perf score=10.126437
I20260812 06:19:15.165550 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.041s	user 0.013s	sys 0.021s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":15356,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":1763584,"update_count":1500}
I20260812 06:19:15.166143 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d): perf score=2.188937
I20260812 06:19:15.179745 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.013s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4645,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:15.180459 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling FlushMRSOp(500775f955d7465e9b094bee98a5a59d): perf score=1.000000
I20260812 06:19:15.215931 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: FlushMRSOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.035s	user 0.031s	sys 0.004s Metrics: {"bytes_written":1152509,"cfile_init":1,"dirs.queue_time_us":81,"dirs.run_cpu_time_us":326,"dirs.run_wall_time_us":1518,"drs_written":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2011,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:15.216807 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling LogGCOp(500775f955d7465e9b094bee98a5a59d): free 121006371 bytes of WAL
I20260812 06:19:15.217068 18822 log_reader.cc:385] T 500775f955d7465e9b094bee98a5a59d: removed 12 log segments from log reader
I20260812 06:19:15.217137 18822 log.cc:1079] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/500775f955d7465e9b094bee98a5a59d/wal-000000002 (ops 7-11)
I20260812 06:19:15.217191 18822 log.cc:1079] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/500775f955d7465e9b094bee98a5a59d/wal-000000003 (ops 12-16)
I20260812 06:19:15.217249 18822 log.cc:1079] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/500775f955d7465e9b094bee98a5a59d/wal-000000004 (ops 17-21)
I20260812 06:19:15.217293 18822 log.cc:1079] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/500775f955d7465e9b094bee98a5a59d/wal-000000005 (ops 22-26)
I20260812 06:19:15.217335 18822 log.cc:1079] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/500775f955d7465e9b094bee98a5a59d/wal-000000006 (ops 27-31)
I20260812 06:19:15.217374 18822 log.cc:1079] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/500775f955d7465e9b094bee98a5a59d/wal-000000007 (ops 32-36)
I20260812 06:19:15.217413 18822 log.cc:1079] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/500775f955d7465e9b094bee98a5a59d/wal-000000008 (ops 37-40)
I20260812 06:19:15.217453 18822 log.cc:1079] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/500775f955d7465e9b094bee98a5a59d/wal-000000009 (ops 41-45)
I20260812 06:19:15.217492 18822 log.cc:1079] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/500775f955d7465e9b094bee98a5a59d/wal-000000010 (ops 46-50)
I20260812 06:19:15.217531 18822 log.cc:1079] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/500775f955d7465e9b094bee98a5a59d/wal-000000011 (ops 51-55)
I20260812 06:19:15.217571 18822 log.cc:1079] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/500775f955d7465e9b094bee98a5a59d/wal-000000012 (ops 56-60)
I20260812 06:19:15.217610 18822 log.cc:1079] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/500775f955d7465e9b094bee98a5a59d/wal-000000013 (ops 61-65)
I20260812 06:19:15.247079 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: LogGCOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.030s	user 0.004s	sys 0.023s Metrics: {}
I20260812 06:19:15.247947 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling UndoDeltaBlockGCOp(500775f955d7465e9b094bee98a5a59d): 447 bytes on disk
I20260812 06:19:15.248519 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: UndoDeltaBlockGCOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":75,"lbm_reads_lt_1ms":4}
I20260812 06:19:15.249159 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d): perf score=4.173312
I20260812 06:19:15.263550 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.014s	user 0.004s	sys 0.008s Metrics: {"bytes_written":5784656,"delete_count":0,"lbm_write_time_us":5870,"lbm_writes_lt_1ms":144,"reinsert_count":0,"update_count":705}
I20260812 06:19:15.264053 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d): perf score=1.196750
I20260812 06:19:15.273653 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.009s	user 0.002s	sys 0.005s Metrics: {"bytes_written":2420629,"delete_count":0,"lbm_write_time_us":2861,"lbm_writes_lt_1ms":62,"reinsert_count":0,"update_count":295}
I20260812 06:19:15.274164 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling MajorDeltaCompactionOp(500775f955d7465e9b094bee98a5a59d): perf score=1.000000
I20260812 06:19:15.455269 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: MajorDeltaCompactionOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.181s	user 0.126s	sys 0.054s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836334,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":293,"lbm_read_time_us":13985,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34567,"lbm_writes_lt_1ms":643,"mutex_wait_us":60,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":10240,"thread_start_us":81,"threads_started":1,"update_count":3000}
I20260812 06:19:15.455858 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d): perf score=14.095187
I20260812 06:19:15.511574 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.053s	user 0.032s	sys 0.016s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22396,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:15.512181 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d): perf score=2.188937
I20260812 06:19:15.524590 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4146,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:15.525195 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling MajorDeltaCompactionOp(500775f955d7465e9b094bee98a5a59d): perf score=1.000000
I20260812 06:19:15.691172 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: MajorDeltaCompactionOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.166s	user 0.139s	sys 0.017s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733725,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":282,"lbm_read_time_us":9940,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32016,"lbm_writes_lt_1ms":543,"mutex_wait_us":32,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:15.692878 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d): perf score=11.118625
I20260812 06:19:15.752807 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.060s	user 0.021s	sys 0.027s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":21634,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:19:15.753295 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d): perf score=2.188937
I20260812 06:19:15.772388 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.019s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4051,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:15.772831 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d): perf score=2.188937
I20260812 06:19:15.782620 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3642,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:15.783054 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling MajorDeltaCompactionOp(500775f955d7465e9b094bee98a5a59d): perf score=1.000000
I20260812 06:19:15.952945 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: MajorDeltaCompactionOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.170s	user 0.112s	sys 0.055s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733834,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1079,"lbm_read_time_us":11057,"lbm_reads_lt_1ms":573,"lbm_write_time_us":27482,"lbm_writes_lt_1ms":543,"mutex_wait_us":310,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:19:15.953568 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d): perf score=14.095187
I20260812 06:19:16.001397 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.048s	user 0.031s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20686,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:16.002058 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling MajorDeltaCompactionOp(500775f955d7465e9b094bee98a5a59d): perf score=1.000000
I20260812 06:19:16.142560 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: MajorDeltaCompactionOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.140s	user 0.096s	sys 0.040s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20631192,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":217,"lbm_read_time_us":9692,"lbm_reads_lt_1ms":463,"lbm_write_time_us":24760,"lbm_writes_lt_1ms":443,"mutex_wait_us":2,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:16.143316 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d): perf score=11.118625
I20260812 06:19:16.182626 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.039s	user 0.028s	sys 0.008s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17434,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:16.183094 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d): perf score=2.188937
I20260812 06:19:16.194828 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4638,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:16.195338 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling MajorDeltaCompactionOp(500775f955d7465e9b094bee98a5a59d): perf score=1.000000
I20260812 06:19:16.324782 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: MajorDeltaCompactionOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.129s	user 0.104s	sys 0.025s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631303,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":325,"lbm_read_time_us":9013,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26533,"lbm_writes_lt_1ms":443,"mutex_wait_us":66,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2000}
I20260812 06:19:16.325321 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d): perf score=10.126437
I20260812 06:19:16.364292 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.039s	user 0.017s	sys 0.020s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16602,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:19:16.364886 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d): perf score=2.188937
I20260812 06:19:16.376190 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.011s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4272,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:16.376688 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling MajorDeltaCompactionOp(500775f955d7465e9b094bee98a5a59d): perf score=1.000000
I20260812 06:19:16.510018 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: MajorDeltaCompactionOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.133s	user 0.099s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":269,"lbm_read_time_us":8760,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26098,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":17920,"update_count":2000}
I20260812 06:19:16.510689 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d): perf score=10.126437
I20260812 06:19:16.560876 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.050s	user 0.021s	sys 0.021s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":20088,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:19:16.561451 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d): perf score=2.188937
I20260812 06:19:16.572746 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4187,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:16.573348 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling FlushMRSOp(500775f955d7465e9b094bee98a5a59d): perf score=1.000000
I20260812 06:19:16.603152 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: FlushMRSOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.030s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":76,"dirs.run_cpu_time_us":243,"dirs.run_wall_time_us":1304,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1421,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:16.604028 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling LogGCOp(500775f955d7465e9b094bee98a5a59d): free 111786322 bytes of WAL
I20260812 06:19:16.604277 18822 log_reader.cc:385] T 500775f955d7465e9b094bee98a5a59d: removed 11 log segments from log reader
I20260812 06:19:16.604347 18822 log.cc:1079] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/500775f955d7465e9b094bee98a5a59d/wal-000000014 (ops 66-70)
I20260812 06:19:16.604403 18822 log.cc:1079] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/500775f955d7465e9b094bee98a5a59d/wal-000000015 (ops 71-75)
I20260812 06:19:16.604439 18822 log.cc:1079] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/500775f955d7465e9b094bee98a5a59d/wal-000000016 (ops 76-80)
I20260812 06:19:16.604477 18822 log.cc:1079] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/500775f955d7465e9b094bee98a5a59d/wal-000000017 (ops 81-84)
I20260812 06:19:16.604518 18822 log.cc:1079] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/500775f955d7465e9b094bee98a5a59d/wal-000000018 (ops 85-89)
I20260812 06:19:16.604557 18822 log.cc:1079] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/500775f955d7465e9b094bee98a5a59d/wal-000000019 (ops 90-94)
I20260812 06:19:16.604593 18822 log.cc:1079] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/500775f955d7465e9b094bee98a5a59d/wal-000000020 (ops 95-99)
I20260812 06:19:16.604629 18822 log.cc:1079] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/500775f955d7465e9b094bee98a5a59d/wal-000000021 (ops 100-104)
I20260812 06:19:16.604666 18822 log.cc:1079] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/500775f955d7465e9b094bee98a5a59d/wal-000000022 (ops 105-109)
I20260812 06:19:16.604709 18822 log.cc:1079] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/500775f955d7465e9b094bee98a5a59d/wal-000000023 (ops 110-114)
I20260812 06:19:16.604745 18822 log.cc:1079] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/500775f955d7465e9b094bee98a5a59d/wal-000000024 (ops 115-118)
I20260812 06:19:16.630108 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: LogGCOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.026s	user 0.004s	sys 0.020s Metrics: {}
I20260812 06:19:16.630632 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling UndoDeltaBlockGCOp(500775f955d7465e9b094bee98a5a59d): 448 bytes on disk
I20260812 06:19:16.631088 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: UndoDeltaBlockGCOp(500775f955d7465e9b094bee98a5a59d) 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:19:16.631801 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d): perf score=2.188937
I20260812 06:19:16.650738 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.019s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4225732,"delete_count":0,"lbm_write_time_us":6395,"lbm_writes_lt_1ms":106,"mutex_wait_us":60,"reinsert_count":0,"update_count":515}
I20260812 06:19:16.651226 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d): perf score=2.188937
I20260812 06:19:16.661644 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3979584,"delete_count":0,"lbm_write_time_us":3901,"lbm_writes_lt_1ms":100,"reinsert_count":0,"update_count":485}
I20260812 06:19:16.662122 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling MajorDeltaCompactionOp(500775f955d7465e9b094bee98a5a59d): perf score=1.000000
I20260812 06:19:16.838502 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: MajorDeltaCompactionOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.176s	user 0.140s	sys 0.036s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836374,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":269,"lbm_read_time_us":14146,"lbm_reads_lt_1ms":674,"lbm_write_time_us":35214,"lbm_writes_lt_1ms":643,"mutex_wait_us":3,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4736,"thread_start_us":77,"threads_started":1,"update_count":3000}
I20260812 06:19:16.839208 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d): perf score=14.095187
I20260812 06:19:16.891964 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.052s	user 0.031s	sys 0.021s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22468,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:16.892874 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d): perf score=2.188937
I20260812 06:19:16.907017 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.014s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4849,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:16.907815 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling MajorDeltaCompactionOp(500775f955d7465e9b094bee98a5a59d): perf score=1.000000
I20260812 06:19:17.074782 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: MajorDeltaCompactionOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.167s	user 0.130s	sys 0.037s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":987,"lbm_read_time_us":10686,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30695,"lbm_writes_lt_1ms":543,"mutex_wait_us":382,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7680,"update_count":2500}
I20260812 06:19:17.075479 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d): perf score=14.095187
I20260812 06:19:17.144255 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.069s	user 0.041s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":28073,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":400,"reinsert_count":0,"update_count":2000}
I20260812 06:19:17.144831 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d): perf score=2.188937
I20260812 06:19:17.157459 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.012s	user 0.009s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4521,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:17.158182 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling MajorDeltaCompactionOp(500775f955d7465e9b094bee98a5a59d): perf score=1.000000
I20260812 06:19:17.342514 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: MajorDeltaCompactionOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.184s	user 0.125s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":286,"lbm_read_time_us":12783,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30541,"lbm_writes_lt_1ms":543,"mutex_wait_us":50,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10752,"update_count":2500}
I20260812 06:19:17.343051 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d): perf score=14.095187
I20260812 06:19:17.400686 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.057s	user 0.028s	sys 0.019s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20407,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:17.401181 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d): perf score=2.188937
I20260812 06:19:17.413266 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4373,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:17.413816 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling MajorDeltaCompactionOp(500775f955d7465e9b094bee98a5a59d): perf score=1.000000
I20260812 06:19:17.582706 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: MajorDeltaCompactionOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.169s	user 0.103s	sys 0.062s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":242,"lbm_read_time_us":11726,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27805,"lbm_writes_lt_1ms":543,"mutex_wait_us":55,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":17408,"update_count":2500}
I20260812 06:19:17.583485 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d): perf score=14.095187
I20260812 06:19:17.649832 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.066s	user 0.022s	sys 0.036s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":21161,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:17.650527 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d): perf score=2.188937
I20260812 06:19:17.662259 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.012s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4586,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:17.662766 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling MajorDeltaCompactionOp(500775f955d7465e9b094bee98a5a59d): perf score=1.000000
I20260812 06:19:17.861359 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: MajorDeltaCompactionOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.198s	user 0.118s	sys 0.068s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733722,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":909,"lbm_read_time_us":14016,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31038,"lbm_writes_lt_1ms":543,"mutex_wait_us":355,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2500}
I20260812 06:19:17.862013 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d): perf score=14.095187
I20260812 06:19:17.912371 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.050s	user 0.024s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21544,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:17.912962 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d): perf score=2.188937
I20260812 06:19:17.935273 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.022s	user 0.007s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4444,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:17.935981 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling MajorDeltaCompactionOp(500775f955d7465e9b094bee98a5a59d): perf score=1.000000
I20260812 06:19:18.129230 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: MajorDeltaCompactionOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.193s	user 0.132s	sys 0.061s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":401,"lbm_read_time_us":13409,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33227,"lbm_writes_lt_1ms":543,"mutex_wait_us":27,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12672,"update_count":2500}
I20260812 06:19:18.129860 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d): perf score=14.095187
I20260812 06:19:18.182530 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.052s	user 0.024s	sys 0.025s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":22940,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:18.183117 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d): perf score=2.188937
I20260812 06:19:18.195283 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4366,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:18.195791 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling FlushMRSOp(500775f955d7465e9b094bee98a5a59d): perf score=1.000000
I20260812 06:19:18.235948 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: FlushMRSOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.040s	user 0.039s	sys 0.000s Metrics: {"bytes_written":1316416,"cfile_init":1,"dirs.queue_time_us":116,"dirs.run_cpu_time_us":198,"dirs.run_wall_time_us":1320,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2410,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:19:18.236819 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling LogGCOp(500775f955d7465e9b094bee98a5a59d): free 137181768 bytes of WAL
I20260812 06:19:18.237126 18822 log_reader.cc:385] T 500775f955d7465e9b094bee98a5a59d: removed 14 log segments from log reader
I20260812 06:19:18.237215 18822 log.cc:1079] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/500775f955d7465e9b094bee98a5a59d/wal-000000025 (ops 119-123)
I20260812 06:19:18.237280 18822 log.cc:1079] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/500775f955d7465e9b094bee98a5a59d/wal-000000026 (ops 124-128)
I20260812 06:19:18.237353 18822 log.cc:1079] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/500775f955d7465e9b094bee98a5a59d/wal-000000027 (ops 129-133)
I20260812 06:19:18.237399 18822 log.cc:1079] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/500775f955d7465e9b094bee98a5a59d/wal-000000028 (ops 134-138)
I20260812 06:19:18.237443 18822 log.cc:1079] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/500775f955d7465e9b094bee98a5a59d/wal-000000029 (ops 139-142)
I20260812 06:19:18.237488 18822 log.cc:1079] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/500775f955d7465e9b094bee98a5a59d/wal-000000030 (ops 143-147)
I20260812 06:19:18.237531 18822 log.cc:1079] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/500775f955d7465e9b094bee98a5a59d/wal-000000031 (ops 148-152)
I20260812 06:19:18.237574 18822 log.cc:1079] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/500775f955d7465e9b094bee98a5a59d/wal-000000032 (ops 153-156)
I20260812 06:19:18.237617 18822 log.cc:1079] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/500775f955d7465e9b094bee98a5a59d/wal-000000033 (ops 157-161)
I20260812 06:19:18.237668 18822 log.cc:1079] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/500775f955d7465e9b094bee98a5a59d/wal-000000034 (ops 162-166)
I20260812 06:19:18.237712 18822 log.cc:1079] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/500775f955d7465e9b094bee98a5a59d/wal-000000035 (ops 167-170)
I20260812 06:19:18.237756 18822 log.cc:1079] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/500775f955d7465e9b094bee98a5a59d/wal-000000036 (ops 171-175)
I20260812 06:19:18.237798 18822 log.cc:1079] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/500775f955d7465e9b094bee98a5a59d/wal-000000037 (ops 176-180)
I20260812 06:19:18.237883 18822 log.cc:1079] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/500775f955d7465e9b094bee98a5a59d/wal-000000038 (ops 181-184)
I20260812 06:19:18.271003 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: LogGCOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.034s	user 0.000s	sys 0.031s Metrics: {}
I20260812 06:19:18.271479 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d): perf score=3.181125
I20260812 06:19:18.289168 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.017s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":4877,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:18.289707 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling UndoDeltaBlockGCOp(500775f955d7465e9b094bee98a5a59d): 491 bytes on disk
I20260812 06:19:18.290268 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: UndoDeltaBlockGCOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":67,"lbm_reads_lt_1ms":4}
I20260812 06:19:18.290891 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d): perf score=2.188937
I20260812 06:19:18.301270 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.010s	user 0.008s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3686,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:18.302071 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling MajorDeltaCompactionOp(500775f955d7465e9b094bee98a5a59d): perf score=1.000000
I20260812 06:19:18.541025 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: MajorDeltaCompactionOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.239s	user 0.154s	sys 0.078s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32938774,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":845,"lbm_read_time_us":14731,"lbm_reads_lt_1ms":774,"lbm_write_time_us":40486,"lbm_writes_lt_1ms":743,"mutex_wait_us":380,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":15872,"thread_start_us":87,"threads_started":1,"update_count":3500}
I20260812 06:19:18.541745 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d): perf score=18.063937
I20260812 06:19:18.600521 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: FlushDeltaMemStoresOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.059s	user 0.028s	sys 0.028s Metrics: {"bytes_written":20512319,"delete_count":0,"lbm_write_time_us":25194,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:18.601157 18894 maintenance_manager.cc:419] P b4a9316feec2499eb0034318ec732763: Scheduling MajorDeltaCompactionOp(500775f955d7465e9b094bee98a5a59d): perf score=1.000000
I20260812 06:19:18.662115 18703 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.958s	user 1.787s	sys 0.176s
I20260812 06:19:18.740360 18703 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.078s	user 0.003s	sys 0.000s
I20260812 06:19:18.741024 18703 tablet_server.cc:179] TabletServer@127.18.67.193:0 shutting down...
I20260812 06:19:18.766589 18822 maintenance_manager.cc:643] P b4a9316feec2499eb0034318ec732763: MajorDeltaCompactionOp(500775f955d7465e9b094bee98a5a59d) complete. Timing: real 0.165s	user 0.089s	sys 0.076s Metrics: {"cfile_cache_miss":531,"cfile_cache_miss_bytes":24733610,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":373,"lbm_read_time_us":11446,"lbm_reads_lt_1ms":559,"lbm_write_time_us":28562,"lbm_writes_lt_1ms":543,"mutex_wait_us":101,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:18.767799 18703 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:18.768333 18703 tablet_replica.cc:333] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763: stopping tablet replica
I20260812 06:19:18.768621 18703 raft_consensus.cc:2243] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:18.768896 18703 raft_consensus.cc:2272] T 500775f955d7465e9b094bee98a5a59d P b4a9316feec2499eb0034318ec732763 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:18.776862 18703 tablet_server.cc:196] TabletServer@127.18.67.193:0 shutdown complete.
I20260812 06:19:18.812928 18703 master.cc:562] Master@127.18.67.254:46723 shutting down...
I20260812 06:19:18.817106 18703 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 4d5010c855044ac18d086255be48467a [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:18.817287 18703 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 4d5010c855044ac18d086255be48467a [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:18.817342 18703 tablet_replica.cc:333] T 00000000000000000000000000000000 P 4d5010c855044ac18d086255be48467a: stopping tablet replica
I20260812 06:19:18.829978 18703 master.cc:584] Master@127.18.67.254:46723 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5501 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:18.939394 18703 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.18.67.254:41731
I20260812 06:19:18.940114 18703 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:18.942530 18929 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:18.942601 18930 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:18.942911 18932 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:18.943112 18703 server_base.cc:1061] running on GCE node
I20260812 06:19:18.943284 18703 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:18.943331 18703 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:18.943378 18703 hybrid_clock.cc:648] HybridClock initialized: now 1786515558943378 us; error 0 us; skew 500 ppm
I20260812 06:19:18.944296 18703 webserver.cc:533] Webserver started at http://127.18.67.254:33181/ using document root <none> and password file <none>
I20260812 06:19:18.944481 18703 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:18.944556 18703 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:18.944648 18703 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:18.945058 18703 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553413118-18703-0/minicluster-data/master-0-root/instance:
uuid: "6a40363efc0a40b0ba0035b1d6a465bc"
format_stamp: "Formatted at 2026-08-12 06:19:18 on dist-test-slave-27sr"
I20260812 06:19:18.946596 18703 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:18.947551 18938 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:18.947794 18703 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:18.947890 18703 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553413118-18703-0/minicluster-data/master-0-root
uuid: "6a40363efc0a40b0ba0035b1d6a465bc"
format_stamp: "Formatted at 2026-08-12 06:19:18 on dist-test-slave-27sr"
I20260812 06:19:18.947983 18703 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553413118-18703-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553413118-18703-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553413118-18703-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:18.966452 18703 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:18.966919 18703 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:18.971704 18703 rpc_server.cc:307] RPC server started. Bound to: 127.18.67.254:41731
I20260812 06:19:18.977005 19009 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.18.67.254:41731 every 8 connection(s)
I20260812 06:19:18.977465 19010 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:18.979324 19010 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 6a40363efc0a40b0ba0035b1d6a465bc: Bootstrap starting.
I20260812 06:19:18.980211 19010 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 6a40363efc0a40b0ba0035b1d6a465bc: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:18.981252 19010 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 6a40363efc0a40b0ba0035b1d6a465bc: No bootstrap required, opened a new log
I20260812 06:19:18.981613 19010 raft_consensus.cc:359] T 00000000000000000000000000000000 P 6a40363efc0a40b0ba0035b1d6a465bc [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6a40363efc0a40b0ba0035b1d6a465bc" member_type: VOTER }
I20260812 06:19:18.981710 19010 raft_consensus.cc:385] T 00000000000000000000000000000000 P 6a40363efc0a40b0ba0035b1d6a465bc [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:18.981743 19010 raft_consensus.cc:740] T 00000000000000000000000000000000 P 6a40363efc0a40b0ba0035b1d6a465bc [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 6a40363efc0a40b0ba0035b1d6a465bc, State: Initialized, Role: FOLLOWER
I20260812 06:19:18.981904 19010 consensus_queue.cc:260] T 00000000000000000000000000000000 P 6a40363efc0a40b0ba0035b1d6a465bc [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: "6a40363efc0a40b0ba0035b1d6a465bc" member_type: VOTER }
I20260812 06:19:18.981997 19010 raft_consensus.cc:399] T 00000000000000000000000000000000 P 6a40363efc0a40b0ba0035b1d6a465bc [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:18.982023 19010 raft_consensus.cc:493] T 00000000000000000000000000000000 P 6a40363efc0a40b0ba0035b1d6a465bc [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:18.982059 19010 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 6a40363efc0a40b0ba0035b1d6a465bc [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:18.982717 19010 raft_consensus.cc:515] T 00000000000000000000000000000000 P 6a40363efc0a40b0ba0035b1d6a465bc [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6a40363efc0a40b0ba0035b1d6a465bc" member_type: VOTER }
I20260812 06:19:18.982867 19010 leader_election.cc:304] T 00000000000000000000000000000000 P 6a40363efc0a40b0ba0035b1d6a465bc [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: 6a40363efc0a40b0ba0035b1d6a465bc; no voters: 
I20260812 06:19:18.983021 19010 leader_election.cc:290] T 00000000000000000000000000000000 P 6a40363efc0a40b0ba0035b1d6a465bc [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:18.983182 19014 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 6a40363efc0a40b0ba0035b1d6a465bc [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:18.983377 19014 raft_consensus.cc:697] T 00000000000000000000000000000000 P 6a40363efc0a40b0ba0035b1d6a465bc [term 1 LEADER]: Becoming Leader. State: Replica: 6a40363efc0a40b0ba0035b1d6a465bc, State: Running, Role: LEADER
I20260812 06:19:18.983546 19010 sys_catalog.cc:565] T 00000000000000000000000000000000 P 6a40363efc0a40b0ba0035b1d6a465bc [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:18.983520 19014 consensus_queue.cc:237] T 00000000000000000000000000000000 P 6a40363efc0a40b0ba0035b1d6a465bc [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: "6a40363efc0a40b0ba0035b1d6a465bc" member_type: VOTER }
I20260812 06:19:18.984038 19016 sys_catalog.cc:455] T 00000000000000000000000000000000 P 6a40363efc0a40b0ba0035b1d6a465bc [sys.catalog]: SysCatalogTable state changed. Reason: New leader 6a40363efc0a40b0ba0035b1d6a465bc. Latest consensus state: current_term: 1 leader_uuid: "6a40363efc0a40b0ba0035b1d6a465bc" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6a40363efc0a40b0ba0035b1d6a465bc" member_type: VOTER } }
I20260812 06:19:18.984138 19016 sys_catalog.cc:458] T 00000000000000000000000000000000 P 6a40363efc0a40b0ba0035b1d6a465bc [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:18.984022 19015 sys_catalog.cc:455] T 00000000000000000000000000000000 P 6a40363efc0a40b0ba0035b1d6a465bc [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "6a40363efc0a40b0ba0035b1d6a465bc" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6a40363efc0a40b0ba0035b1d6a465bc" member_type: VOTER } }
I20260812 06:19:18.984192 19015 sys_catalog.cc:458] T 00000000000000000000000000000000 P 6a40363efc0a40b0ba0035b1d6a465bc [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:18.984416 19018 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:18.985231 19018 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:18.985596 18703 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:18.987226 19018 catalog_manager.cc:1383] Generated new cluster ID: 0255d3a9fcfb4f0287d2e926b287ee34
I20260812 06:19:18.987293 19018 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:19.010900 19018 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:19.011523 19018 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:19.028808 19018 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 6a40363efc0a40b0ba0035b1d6a465bc: Generated new TSK 0
I20260812 06:19:19.029084 19018 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:19.050374 18703 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:19.052523 19035 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:19.052613 19040 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:19.052805 19038 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:19.052868 18703 server_base.cc:1061] running on GCE node
I20260812 06:19:19.053157 18703 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:19.053223 18703 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:19.053257 18703 hybrid_clock.cc:648] HybridClock initialized: now 1786515559053256 us; error 0 us; skew 500 ppm
I20260812 06:19:19.054224 18703 webserver.cc:533] Webserver started at http://127.18.67.193:38737/ using document root <none> and password file <none>
I20260812 06:19:19.054425 18703 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:19.054500 18703 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:19.054582 18703 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:19.055292 18703 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553413118-18703-0/minicluster-data/ts-0-root/instance:
uuid: "4b7a306182094db0bbfb2493963131d6"
format_stamp: "Formatted at 2026-08-12 06:19:19 on dist-test-slave-27sr"
I20260812 06:19:19.057139 18703 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.003s
I20260812 06:19:19.058223 19046 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:19.058507 18703 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:19.058602 18703 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553413118-18703-0/minicluster-data/ts-0-root
uuid: "4b7a306182094db0bbfb2493963131d6"
format_stamp: "Formatted at 2026-08-12 06:19:19 on dist-test-slave-27sr"
I20260812 06:19:19.058709 18703 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553413118-18703-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553413118-18703-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553413118-18703-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:19.065445 18703 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:19.065876 18703 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:19.066205 18703 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:19.066684 18703 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:19.066745 18703 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:19.066819 18703 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:19.066871 18703 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:19.071280 18703 rpc_server.cc:307] RPC server started. Bound to: 127.18.67.193:38903
I20260812 06:19:19.071986 19119 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.18.67.193:38903 every 8 connection(s)
I20260812 06:19:19.081985 19120 heartbeater.cc:344] Connected to a master server at 127.18.67.254:41731
I20260812 06:19:19.082121 19120 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:19.082427 19120 heartbeater.cc:507] Master 127.18.67.254:41731 requested a full tablet report, sending...
I20260812 06:19:19.083154 18961 ts_manager.cc:194] Registered new tserver with Master: 4b7a306182094db0bbfb2493963131d6 (127.18.67.193:38903)
I20260812 06:19:19.083392 18703 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011252853s
I20260812 06:19:19.084107 18961 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:39480
I20260812 06:19:19.091092 18961 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:39488:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:19.101135 19077 tablet_service.cc:1511] Processing CreateTablet for tablet 6f0f26eebe0b40b6973c1675074d9746 (DEFAULT_TABLE table=heavy-update-compaction-test [id=36371530472b45328e50dab5f16df2dd]), partition=
I20260812 06:19:19.101390 19077 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 6f0f26eebe0b40b6973c1675074d9746. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:19.103461 19138 tablet_bootstrap.cc:492] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6: Bootstrap starting.
I20260812 06:19:19.104446 19138 tablet_bootstrap.cc:654] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:19.105621 19138 tablet_bootstrap.cc:492] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6: No bootstrap required, opened a new log
I20260812 06:19:19.105738 19138 ts_tablet_manager.cc:1403] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:19.106245 19138 raft_consensus.cc:359] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4b7a306182094db0bbfb2493963131d6" member_type: VOTER last_known_addr { host: "127.18.67.193" port: 38903 } }
I20260812 06:19:19.106379 19138 raft_consensus.cc:385] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:19.106429 19138 raft_consensus.cc:740] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 4b7a306182094db0bbfb2493963131d6, State: Initialized, Role: FOLLOWER
I20260812 06:19:19.106576 19138 consensus_queue.cc:260] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6 [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: "4b7a306182094db0bbfb2493963131d6" member_type: VOTER last_known_addr { host: "127.18.67.193" port: 38903 } }
I20260812 06:19:19.106673 19138 raft_consensus.cc:399] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:19.106760 19138 raft_consensus.cc:493] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:19.106823 19138 raft_consensus.cc:3060] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:19.107601 19138 raft_consensus.cc:515] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4b7a306182094db0bbfb2493963131d6" member_type: VOTER last_known_addr { host: "127.18.67.193" port: 38903 } }
I20260812 06:19:19.107731 19138 leader_election.cc:304] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6 [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: 4b7a306182094db0bbfb2493963131d6; no voters: 
I20260812 06:19:19.108012 19138 leader_election.cc:290] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:19.108161 19141 raft_consensus.cc:2804] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:19.108417 19138 ts_tablet_manager.cc:1434] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6: Time spent starting tablet: real 0.003s	user 0.001s	sys 0.001s
I20260812 06:19:19.108433 19120 heartbeater.cc:499] Master 127.18.67.254:41731 was elected leader, sending a full tablet report...
I20260812 06:19:19.108461 19141 raft_consensus.cc:697] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6 [term 1 LEADER]: Becoming Leader. State: Replica: 4b7a306182094db0bbfb2493963131d6, State: Running, Role: LEADER
I20260812 06:19:19.108666 19141 consensus_queue.cc:237] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6 [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: "4b7a306182094db0bbfb2493963131d6" member_type: VOTER last_known_addr { host: "127.18.67.193" port: 38903 } }
I20260812 06:19:19.110020 18961 catalog_manager.cc:5719] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6 reported cstate change: term changed from 0 to 1, leader changed from <none> to 4b7a306182094db0bbfb2493963131d6 (127.18.67.193). New cstate: current_term: 1 leader_uuid: "4b7a306182094db0bbfb2493963131d6" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4b7a306182094db0bbfb2493963131d6" member_type: VOTER last_known_addr { host: "127.18.67.193" port: 38903 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:19.170560 18703 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.054s	user 0.019s	sys 0.004s
I20260812 06:19:19.322964 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling FlushMRSOp(6f0f26eebe0b40b6973c1675074d9746): perf score=19.054940
I20260812 06:19:19.481945 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: FlushMRSOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.159s	user 0.113s	sys 0.043s Metrics: {"bytes_written":12717734,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":77,"dirs.run_cpu_time_us":185,"dirs.run_wall_time_us":879,"drs_written":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4,"lbm_write_time_us":37032,"lbm_writes_lt_1ms":767,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":4864,"update_count":1550}
I20260812 06:19:19.482874 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling LogGCOp(6f0f26eebe0b40b6973c1675074d9746): free 20743880 bytes of WAL
I20260812 06:19:19.483323 19051 log_reader.cc:385] T 6f0f26eebe0b40b6973c1675074d9746: removed 2 log segments from log reader
I20260812 06:19:19.483397 19051 log.cc:1079] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/6f0f26eebe0b40b6973c1675074d9746/wal-000000001 (ops 1-6)
I20260812 06:19:19.483443 19051 log.cc:1079] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/6f0f26eebe0b40b6973c1675074d9746/wal-000000002 (ops 7-11)
I20260812 06:19:19.488194 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: LogGCOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.005s	user 0.000s	sys 0.005s Metrics: {}
I20260812 06:19:19.488541 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746): perf score=2.188937
I20260812 06:19:19.513093 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.024s	user 0.004s	sys 0.006s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3846,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:19.513741 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746): perf score=2.188937
I20260812 06:19:19.528956 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5785,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:19.529611 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling MajorDeltaCompactionOp(6f0f26eebe0b40b6973c1675074d9746): perf score=1.000000
I20260812 06:19:19.730480 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: MajorDeltaCompactionOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.201s	user 0.140s	sys 0.060s 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":628,"lbm_read_time_us":13801,"lbm_reads_lt_1ms":573,"lbm_write_time_us":34221,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1920,"thread_start_us":310,"threads_started":5,"update_count":2500}
I20260812 06:19:19.730988 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746): perf score=14.095187
I20260812 06:19:19.788995 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.058s	user 0.039s	sys 0.012s Metrics: {"bytes_written":16409906,"delete_count":0,"lbm_write_time_us":23444,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:19.789544 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746): perf score=2.188937
I20260812 06:19:19.800722 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4091,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:19.801332 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling MajorDeltaCompactionOp(6f0f26eebe0b40b6973c1675074d9746): perf score=1.000000
I20260812 06:19:19.983837 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: MajorDeltaCompactionOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.182s	user 0.103s	sys 0.076s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774693,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":749,"lbm_read_time_us":13088,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29911,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14080,"update_count":2500}
I20260812 06:19:19.984602 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling UndoDeltaBlockGCOp(6f0f26eebe0b40b6973c1675074d9746): 16411392 bytes on disk
I20260812 06:19:19.985219 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: UndoDeltaBlockGCOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":106,"lbm_reads_lt_1ms":4}
I20260812 06:19:19.985862 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746): perf score=14.095187
I20260812 06:19:20.046283 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.060s	user 0.033s	sys 0.025s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23169,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:20.046864 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746): perf score=2.188937
I20260812 06:19:20.058063 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4312,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:20.058553 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling MajorDeltaCompactionOp(6f0f26eebe0b40b6973c1675074d9746): perf score=1.000000
I20260812 06:19:20.233206 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: MajorDeltaCompactionOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.174s	user 0.102s	sys 0.072s 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":1035,"lbm_read_time_us":12082,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28733,"lbm_writes_lt_1ms":543,"mutex_wait_us":284,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12416,"update_count":2500}
I20260812 06:19:20.233752 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746): perf score=14.095187
I20260812 06:19:20.300508 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.067s	user 0.027s	sys 0.038s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":26813,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:20.301081 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746): perf score=2.188937
I20260812 06:19:20.312070 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4333,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:20.312541 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling MajorDeltaCompactionOp(6f0f26eebe0b40b6973c1675074d9746): perf score=1.000000
I20260812 06:19:20.509271 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: MajorDeltaCompactionOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.197s	user 0.123s	sys 0.063s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":281,"lbm_read_time_us":14338,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30258,"lbm_writes_lt_1ms":543,"mutex_wait_us":55,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12672,"update_count":2500}
I20260812 06:19:20.510305 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746): perf score=14.095187
I20260812 06:19:20.563829 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.053s	user 0.020s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21280,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:20.564410 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746): perf score=2.188937
I20260812 06:19:20.591741 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.027s	user 0.012s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6477,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:20.592427 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling MajorDeltaCompactionOp(6f0f26eebe0b40b6973c1675074d9746): perf score=1.000000
I20260812 06:19:20.785804 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: MajorDeltaCompactionOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.193s	user 0.112s	sys 0.076s 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":1138,"lbm_read_time_us":14051,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31560,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":542,"mutex_wait_us":60,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:19:20.786453 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746): perf score=14.095187
I20260812 06:19:20.839488 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.053s	user 0.003s	sys 0.035s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18824,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:20.840108 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746): perf score=2.188937
I20260812 06:19:20.852696 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.012s	user 0.001s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4651,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:20.853250 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling FlushMRSOp(6f0f26eebe0b40b6973c1675074d9746): perf score=1.000000
I20260812 06:19:20.897809 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: FlushMRSOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.044s	user 0.032s	sys 0.011s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":135,"dirs.run_cpu_time_us":255,"dirs.run_wall_time_us":1506,"drs_written":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1692,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:20.898682 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling LogGCOp(6f0f26eebe0b40b6973c1675074d9746): free 124257239 bytes of WAL
I20260812 06:19:20.898988 19051 log_reader.cc:385] T 6f0f26eebe0b40b6973c1675074d9746: removed 12 log segments from log reader
I20260812 06:19:20.899053 19051 log.cc:1079] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/6f0f26eebe0b40b6973c1675074d9746/wal-000000003 (ops 12-16)
I20260812 06:19:20.899109 19051 log.cc:1079] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/6f0f26eebe0b40b6973c1675074d9746/wal-000000004 (ops 17-21)
I20260812 06:19:20.899173 19051 log.cc:1079] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/6f0f26eebe0b40b6973c1675074d9746/wal-000000005 (ops 22-26)
I20260812 06:19:20.899212 19051 log.cc:1079] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/6f0f26eebe0b40b6973c1675074d9746/wal-000000006 (ops 27-31)
I20260812 06:19:20.899248 19051 log.cc:1079] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/6f0f26eebe0b40b6973c1675074d9746/wal-000000007 (ops 32-36)
I20260812 06:19:20.899286 19051 log.cc:1079] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/6f0f26eebe0b40b6973c1675074d9746/wal-000000008 (ops 37-41)
I20260812 06:19:20.899320 19051 log.cc:1079] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/6f0f26eebe0b40b6973c1675074d9746/wal-000000009 (ops 42-46)
I20260812 06:19:20.899358 19051 log.cc:1079] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/6f0f26eebe0b40b6973c1675074d9746/wal-000000010 (ops 47-50)
I20260812 06:19:20.899394 19051 log.cc:1079] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/6f0f26eebe0b40b6973c1675074d9746/wal-000000011 (ops 51-55)
I20260812 06:19:20.899430 19051 log.cc:1079] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/6f0f26eebe0b40b6973c1675074d9746/wal-000000012 (ops 56-60)
I20260812 06:19:20.899466 19051 log.cc:1079] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/6f0f26eebe0b40b6973c1675074d9746/wal-000000013 (ops 61-65)
I20260812 06:19:20.899501 19051 log.cc:1079] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/6f0f26eebe0b40b6973c1675074d9746/wal-000000014 (ops 66-70)
I20260812 06:19:20.925629 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: LogGCOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.027s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:19:20.926358 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling UndoDeltaBlockGCOp(6f0f26eebe0b40b6973c1675074d9746): 473 bytes on disk
I20260812 06:19:20.927104 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: UndoDeltaBlockGCOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":101,"lbm_reads_lt_1ms":4}
I20260812 06:19:20.927868 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746): perf score=2.188937
I20260812 06:19:20.949574 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.021s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6742,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:20.950193 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling MajorDeltaCompactionOp(6f0f26eebe0b40b6973c1675074d9746): perf score=1.000000
I20260812 06:19:21.173975 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: MajorDeltaCompactionOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.224s	user 0.152s	sys 0.071s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877219,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1046,"lbm_read_time_us":17310,"lbm_reads_lt_1ms":665,"lbm_write_time_us":37178,"lbm_writes_lt_1ms":643,"mutex_wait_us":120,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12032,"thread_start_us":95,"threads_started":1,"update_count":3000}
I20260812 06:19:21.174793 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746): perf score=18.063937
I20260812 06:19:21.252691 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.078s	user 0.030s	sys 0.047s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":30050,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:21.253265 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746): perf score=2.188937
I20260812 06:19:21.265425 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.012s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4737,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:21.265909 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling MajorDeltaCompactionOp(6f0f26eebe0b40b6973c1675074d9746): perf score=1.000000
I20260812 06:19:21.483692 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: MajorDeltaCompactionOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.218s	user 0.133s	sys 0.084s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":311,"lbm_read_time_us":15361,"lbm_reads_lt_1ms":672,"lbm_write_time_us":37615,"lbm_writes_lt_1ms":643,"mutex_wait_us":55,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12288,"update_count":3000}
I20260812 06:19:21.484401 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746): perf score=14.095187
I20260812 06:19:21.529928 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.045s	user 0.020s	sys 0.023s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":20466,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:21.530488 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746): perf score=2.188937
I20260812 06:19:21.541334 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4140,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:21.541786 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling MajorDeltaCompactionOp(6f0f26eebe0b40b6973c1675074d9746): perf score=1.000000
I20260812 06:19:21.727368 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: MajorDeltaCompactionOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.185s	user 0.111s	sys 0.069s 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":353,"lbm_read_time_us":13206,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30102,"lbm_writes_lt_1ms":543,"mutex_wait_us":65,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11520,"update_count":2500}
I20260812 06:19:21.728096 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746): perf score=14.095187
I20260812 06:19:21.795737 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.067s	user 0.023s	sys 0.031s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":20371,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:21.796402 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746): perf score=2.188937
I20260812 06:19:21.807816 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.011s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4239,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:21.808435 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling MajorDeltaCompactionOp(6f0f26eebe0b40b6973c1675074d9746): perf score=1.000000
I20260812 06:19:21.998648 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: MajorDeltaCompactionOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.190s	user 0.105s	sys 0.073s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1171,"lbm_read_time_us":13121,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29856,"lbm_writes_lt_1ms":543,"mutex_wait_us":69,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9216,"update_count":2500}
I20260812 06:19:21.999228 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746): perf score=14.095187
I20260812 06:19:22.072925 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.073s	user 0.058s	sys 0.014s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":27066,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:22.073572 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746): perf score=2.188937
I20260812 06:19:22.085281 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.011s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4297,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:22.085795 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling MajorDeltaCompactionOp(6f0f26eebe0b40b6973c1675074d9746): perf score=1.000000
I20260812 06:19:22.291225 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: MajorDeltaCompactionOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.205s	user 0.142s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":305,"lbm_read_time_us":14050,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34597,"lbm_writes_lt_1ms":543,"mutex_wait_us":43,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16256,"update_count":2500}
I20260812 06:19:22.291986 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746): perf score=14.095187
I20260812 06:19:22.346956 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.055s	user 0.025s	sys 0.024s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":25383,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:22.347487 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746): perf score=2.188937
I20260812 06:19:22.369304 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.022s	user 0.006s	sys 0.014s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4232,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:22.370028 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling MajorDeltaCompactionOp(6f0f26eebe0b40b6973c1675074d9746): perf score=1.000000
I20260812 06:19:22.567044 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: MajorDeltaCompactionOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.197s	user 0.146s	sys 0.039s 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":911,"lbm_read_time_us":13150,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34143,"lbm_writes_lt_1ms":543,"mutex_wait_us":341,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":2500}
I20260812 06:19:22.567745 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746): perf score=14.095187
I20260812 06:19:22.627723 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.060s	user 0.038s	sys 0.018s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":27714,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:22.628396 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746): perf score=2.188937
I20260812 06:19:22.640832 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.012s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4483,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:22.641436 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling FlushMRSOp(6f0f26eebe0b40b6973c1675074d9746): perf score=1.000000
I20260812 06:19:22.686414 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: FlushMRSOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.045s	user 0.032s	sys 0.010s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":56,"dirs.run_cpu_time_us":217,"dirs.run_wall_time_us":1301,"drs_written":1,"lbm_read_time_us":67,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1753,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:19:22.687311 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling LogGCOp(6f0f26eebe0b40b6973c1675074d9746): free 133024390 bytes of WAL
I20260812 06:19:22.687572 19051 log_reader.cc:385] T 6f0f26eebe0b40b6973c1675074d9746: removed 13 log segments from log reader
I20260812 06:19:22.687633 19051 log.cc:1079] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/6f0f26eebe0b40b6973c1675074d9746/wal-000000015 (ops 71-75)
I20260812 06:19:22.687690 19051 log.cc:1079] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/6f0f26eebe0b40b6973c1675074d9746/wal-000000016 (ops 76-80)
I20260812 06:19:22.687747 19051 log.cc:1079] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/6f0f26eebe0b40b6973c1675074d9746/wal-000000017 (ops 81-85)
I20260812 06:19:22.687790 19051 log.cc:1079] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/6f0f26eebe0b40b6973c1675074d9746/wal-000000018 (ops 86-90)
I20260812 06:19:22.687827 19051 log.cc:1079] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/6f0f26eebe0b40b6973c1675074d9746/wal-000000019 (ops 91-95)
I20260812 06:19:22.687867 19051 log.cc:1079] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/6f0f26eebe0b40b6973c1675074d9746/wal-000000020 (ops 96-100)
I20260812 06:19:22.687930 19051 log.cc:1079] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/6f0f26eebe0b40b6973c1675074d9746/wal-000000021 (ops 101-104)
I20260812 06:19:22.687971 19051 log.cc:1079] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/6f0f26eebe0b40b6973c1675074d9746/wal-000000022 (ops 105-109)
I20260812 06:19:22.688007 19051 log.cc:1079] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/6f0f26eebe0b40b6973c1675074d9746/wal-000000023 (ops 110-114)
I20260812 06:19:22.688045 19051 log.cc:1079] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/6f0f26eebe0b40b6973c1675074d9746/wal-000000024 (ops 115-119)
I20260812 06:19:22.688081 19051 log.cc:1079] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/6f0f26eebe0b40b6973c1675074d9746/wal-000000025 (ops 120-124)
I20260812 06:19:22.688119 19051 log.cc:1079] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/6f0f26eebe0b40b6973c1675074d9746/wal-000000026 (ops 125-129)
I20260812 06:19:22.688155 19051 log.cc:1079] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/6f0f26eebe0b40b6973c1675074d9746/wal-000000027 (ops 130-134)
I20260812 06:19:22.720124 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: LogGCOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.033s	user 0.002s	sys 0.031s Metrics: {}
I20260812 06:19:22.720585 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling UndoDeltaBlockGCOp(6f0f26eebe0b40b6973c1675074d9746): 492 bytes on disk
I20260812 06:19:22.721237 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: UndoDeltaBlockGCOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":100,"lbm_reads_lt_1ms":4}
I20260812 06:19:22.721989 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746): perf score=3.181125
I20260812 06:19:22.750162 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.028s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4512901,"delete_count":0,"lbm_write_time_us":6719,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:22.750700 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746): perf score=2.188937
I20260812 06:19:22.760473 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3561,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:22.760962 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling MajorDeltaCompactionOp(6f0f26eebe0b40b6973c1675074d9746): perf score=1.000000
I20260812 06:19:23.030298 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: MajorDeltaCompactionOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.269s	user 0.173s	sys 0.084s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979735,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":647,"lbm_read_time_us":16896,"lbm_reads_lt_1ms":774,"lbm_write_time_us":43919,"lbm_writes_lt_1ms":743,"mutex_wait_us":28,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":15872,"thread_start_us":99,"threads_started":1,"update_count":3500}
I20260812 06:19:23.031083 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746): perf score=18.063937
I20260812 06:19:23.109031 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.078s	user 0.035s	sys 0.040s Metrics: {"bytes_written":20512314,"delete_count":0,"lbm_write_time_us":34706,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":501,"reinsert_count":0,"update_count":2500}
I20260812 06:19:23.109582 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746): perf score=2.188937
I20260812 06:19:23.122359 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4671,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:23.122923 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling MajorDeltaCompactionOp(6f0f26eebe0b40b6973c1675074d9746): perf score=1.000000
I20260812 06:19:23.343797 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: MajorDeltaCompactionOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.220s	user 0.144s	sys 0.076s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877101,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":603,"lbm_read_time_us":14870,"lbm_reads_lt_1ms":672,"lbm_write_time_us":38194,"lbm_writes_lt_1ms":643,"mutex_wait_us":2,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":8832,"update_count":3000}
I20260812 06:19:23.344697 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746): perf score=14.095187
I20260812 06:19:23.393481 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.048s	user 0.033s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19750,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:23.394130 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746): perf score=2.188937
I20260812 06:19:23.406291 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4711,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:23.406944 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling MajorDeltaCompactionOp(6f0f26eebe0b40b6973c1675074d9746): perf score=1.000000
I20260812 06:19:23.609896 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: MajorDeltaCompactionOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.203s	user 0.150s	sys 0.052s 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":450,"lbm_read_time_us":13701,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34305,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":29440,"update_count":2500}
I20260812 06:19:23.610633 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746): perf score=14.095187
I20260812 06:19:23.664180 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.053s	user 0.036s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19999,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:23.664832 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746): perf score=2.188937
I20260812 06:19:23.683081 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.018s	user 0.004s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6926,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:23.683737 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling MajorDeltaCompactionOp(6f0f26eebe0b40b6973c1675074d9746): perf score=1.000000
I20260812 06:19:23.858381 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: MajorDeltaCompactionOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.174s	user 0.126s	sys 0.046s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":360,"lbm_read_time_us":11252,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30336,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2500}
I20260812 06:19:23.859364 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746): perf score=14.095187
I20260812 06:19:23.912647 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.053s	user 0.033s	sys 0.019s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":18481,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:23.913328 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746): perf score=2.188937
I20260812 06:19:23.925535 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.012s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4779,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:23.926295 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling MajorDeltaCompactionOp(6f0f26eebe0b40b6973c1675074d9746): perf score=1.000000
I20260812 06:19:24.105734 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: MajorDeltaCompactionOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.179s	user 0.101s	sys 0.066s 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":316,"lbm_read_time_us":13683,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26527,"lbm_writes_lt_1ms":543,"mutex_wait_us":43,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:24.106385 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746): perf score=14.095187
I20260812 06:19:24.180092 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.073s	user 0.021s	sys 0.051s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":28409,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:24.180843 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746): perf score=2.188937
I20260812 06:19:24.193356 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.012s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4781,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:24.193887 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling FlushMRSOp(6f0f26eebe0b40b6973c1675074d9746): perf score=1.000000
I20260812 06:19:24.237315 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: FlushMRSOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.043s	user 0.029s	sys 0.003s Metrics: {"bytes_written":1152512,"cfile_init":1,"dirs.queue_time_us":70,"dirs.run_cpu_time_us":253,"dirs.run_wall_time_us":1465,"drs_written":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2076,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:24.238086 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling LogGCOp(6f0f26eebe0b40b6973c1675074d9746): free 112239554 bytes of WAL
I20260812 06:19:24.238332 19051 log_reader.cc:385] T 6f0f26eebe0b40b6973c1675074d9746: removed 11 log segments from log reader
I20260812 06:19:24.238387 19051 log.cc:1079] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/6f0f26eebe0b40b6973c1675074d9746/wal-000000028 (ops 135-139)
I20260812 06:19:24.238416 19051 log.cc:1079] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/6f0f26eebe0b40b6973c1675074d9746/wal-000000029 (ops 140-144)
I20260812 06:19:24.238479 19051 log.cc:1079] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/6f0f26eebe0b40b6973c1675074d9746/wal-000000030 (ops 145-149)
I20260812 06:19:24.238521 19051 log.cc:1079] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/6f0f26eebe0b40b6973c1675074d9746/wal-000000031 (ops 150-154)
I20260812 06:19:24.238562 19051 log.cc:1079] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/6f0f26eebe0b40b6973c1675074d9746/wal-000000032 (ops 155-159)
I20260812 06:19:24.238602 19051 log.cc:1079] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/6f0f26eebe0b40b6973c1675074d9746/wal-000000033 (ops 160-164)
I20260812 06:19:24.238662 19051 log.cc:1079] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/6f0f26eebe0b40b6973c1675074d9746/wal-000000034 (ops 165-169)
I20260812 06:19:24.238701 19051 log.cc:1079] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/6f0f26eebe0b40b6973c1675074d9746/wal-000000035 (ops 170-174)
I20260812 06:19:24.238741 19051 log.cc:1079] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/6f0f26eebe0b40b6973c1675074d9746/wal-000000036 (ops 175-179)
I20260812 06:19:24.238781 19051 log.cc:1079] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/6f0f26eebe0b40b6973c1675074d9746/wal-000000037 (ops 180-184)
I20260812 06:19:24.238821 19051 log.cc:1079] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6: Deleting log segment in path: /tmp/dist-test-task6T59B2/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515553413118-18703-0/minicluster-data/ts-0-root/wals/6f0f26eebe0b40b6973c1675074d9746/wal-000000038 (ops 185-188)
I20260812 06:19:24.264115 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: LogGCOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.026s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:24.264626 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling UndoDeltaBlockGCOp(6f0f26eebe0b40b6973c1675074d9746): 448 bytes on disk
I20260812 06:19:24.265270 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: UndoDeltaBlockGCOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":119,"lbm_reads_lt_1ms":4}
I20260812 06:19:24.265970 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746): perf score=3.181125
I20260812 06:19:24.284140 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.018s	user 0.005s	sys 0.007s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4597,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:24.284816 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746): perf score=2.188937
I20260812 06:19:24.299347 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5390,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:24.300127 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling MajorDeltaCompactionOp(6f0f26eebe0b40b6973c1675074d9746): perf score=1.000000
I20260812 06:19:24.488620 18703 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.318s	user 1.969s	sys 0.199s
I20260812 06:19:24.529482 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: MajorDeltaCompactionOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.229s	user 0.152s	sys 0.076s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979738,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":15570,"lbm_reads_lt_1ms":770,"lbm_write_time_us":38608,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":3500}
I20260812 06:19:24.530073 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746): perf score=14.095187
I20260812 06:19:24.563616 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: FlushDeltaMemStoresOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.033s	user 0.028s	sys 0.004s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":16261,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":3072,"update_count":2000}
I20260812 06:19:24.564204 19122 maintenance_manager.cc:419] P 4b7a306182094db0bbfb2493963131d6: Scheduling MajorDeltaCompactionOp(6f0f26eebe0b40b6973c1675074d9746): perf score=1.000000
I20260812 06:19:24.601920 18703 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.113s	user 0.001s	sys 0.000s
I20260812 06:19:24.603142 18703 tablet_server.cc:179] TabletServer@127.18.67.193:0 shutting down...
I20260812 06:19:24.688200 19051 maintenance_manager.cc:643] P 4b7a306182094db0bbfb2493963131d6: MajorDeltaCompactionOp(6f0f26eebe0b40b6973c1675074d9746) complete. Timing: real 0.124s	user 0.087s	sys 0.036s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672158,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":979,"lbm_read_time_us":10827,"lbm_reads_lt_1ms":467,"lbm_write_time_us":23715,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":32,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":828032,"update_count":2000}
I20260812 06:19:24.689266 18703 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:24.689538 18703 tablet_replica.cc:333] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6: stopping tablet replica
I20260812 06:19:24.689738 18703 raft_consensus.cc:2243] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:24.689926 18703 raft_consensus.cc:2272] T 6f0f26eebe0b40b6973c1675074d9746 P 4b7a306182094db0bbfb2493963131d6 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:24.694527 18703 tablet_server.cc:196] TabletServer@127.18.67.193:0 shutdown complete.
I20260812 06:19:24.728415 18703 master.cc:562] Master@127.18.67.254:41731 shutting down...
I20260812 06:19:24.731946 18703 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 6a40363efc0a40b0ba0035b1d6a465bc [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:24.732136 18703 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 6a40363efc0a40b0ba0035b1d6a465bc [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:24.732188 18703 tablet_replica.cc:333] T 00000000000000000000000000000000 P 6a40363efc0a40b0ba0035b1d6a465bc: stopping tablet replica
I20260812 06:19:24.744836 18703 master.cc:584] Master@127.18.67.254:41731 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5912 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11415 ms total)

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