[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:17:00.425154   840 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.0.210.62:32895
I20260812 06:17:00.426568   840 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:17:00.427374   840 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:00.435675   849 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:00.435757   846 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:00.436059   847 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:00.436033   840 server_base.cc:1061] running on GCE node
I20260812 06:17:00.437338   840 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:00.437496   840 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:00.437587   840 hybrid_clock.cc:648] HybridClock initialized: now 1786515420437582 us; error 0 us; skew 500 ppm
I20260812 06:17:00.440694   840 webserver.cc:533] Webserver started at http://127.0.210.62:36587/ using document root <none> and password file <none>
I20260812 06:17:00.441545   840 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:00.441635   840 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:00.441942   840 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:00.444090   840 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420410567-840-0/minicluster-data/master-0-root/instance:
uuid: "306622a98948468a8dd16e5b1955a941"
format_stamp: "Formatted at 2026-08-12 06:17:00 on dist-test-slave-77v9"
I20260812 06:17:00.449790   840 fs_manager.cc:696] Time spent creating directory manager: real 0.005s	user 0.007s	sys 0.000s
I20260812 06:17:00.454319   854 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:00.456600   840 fs_manager.cc:730] Time spent opening block manager: real 0.005s	user 0.004s	sys 0.001s
I20260812 06:17:00.457015   840 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420410567-840-0/minicluster-data/master-0-root
uuid: "306622a98948468a8dd16e5b1955a941"
format_stamp: "Formatted at 2026-08-12 06:17:00 on dist-test-slave-77v9"
I20260812 06:17:00.457197   840 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420410567-840-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420410567-840-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420410567-840-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:00.483430   840 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:00.484308   840 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:17:00.484551   840 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:00.495294   840 rpc_server.cc:307] RPC server started. Bound to: 127.0.210.62:32895
I20260812 06:17:00.495294   914 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.0.210.62:32895 every 8 connection(s)
I20260812 06:17:00.498939   915 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:00.506982   915 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 306622a98948468a8dd16e5b1955a941: Bootstrap starting.
I20260812 06:17:00.510155   915 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 306622a98948468a8dd16e5b1955a941: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:00.511511   915 log.cc:826] T 00000000000000000000000000000000 P 306622a98948468a8dd16e5b1955a941: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:00.514497   915 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 306622a98948468a8dd16e5b1955a941: No bootstrap required, opened a new log
I20260812 06:17:00.518990   915 raft_consensus.cc:359] T 00000000000000000000000000000000 P 306622a98948468a8dd16e5b1955a941 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "306622a98948468a8dd16e5b1955a941" member_type: VOTER }
I20260812 06:17:00.519279   915 raft_consensus.cc:385] T 00000000000000000000000000000000 P 306622a98948468a8dd16e5b1955a941 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:00.519338   915 raft_consensus.cc:740] T 00000000000000000000000000000000 P 306622a98948468a8dd16e5b1955a941 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 306622a98948468a8dd16e5b1955a941, State: Initialized, Role: FOLLOWER
I20260812 06:17:00.520260   915 consensus_queue.cc:260] T 00000000000000000000000000000000 P 306622a98948468a8dd16e5b1955a941 [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: "306622a98948468a8dd16e5b1955a941" member_type: VOTER }
I20260812 06:17:00.520489   915 raft_consensus.cc:399] T 00000000000000000000000000000000 P 306622a98948468a8dd16e5b1955a941 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:00.520547   915 raft_consensus.cc:493] T 00000000000000000000000000000000 P 306622a98948468a8dd16e5b1955a941 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:00.520768   915 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 306622a98948468a8dd16e5b1955a941 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:00.521986   915 raft_consensus.cc:515] T 00000000000000000000000000000000 P 306622a98948468a8dd16e5b1955a941 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "306622a98948468a8dd16e5b1955a941" member_type: VOTER }
I20260812 06:17:00.522634   915 leader_election.cc:304] T 00000000000000000000000000000000 P 306622a98948468a8dd16e5b1955a941 [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: 306622a98948468a8dd16e5b1955a941; no voters: 
I20260812 06:17:00.523092   915 leader_election.cc:290] T 00000000000000000000000000000000 P 306622a98948468a8dd16e5b1955a941 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:00.523362   919 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 306622a98948468a8dd16e5b1955a941 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:00.523679   919 raft_consensus.cc:697] T 00000000000000000000000000000000 P 306622a98948468a8dd16e5b1955a941 [term 1 LEADER]: Becoming Leader. State: Replica: 306622a98948468a8dd16e5b1955a941, State: Running, Role: LEADER
I20260812 06:17:00.524179   919 consensus_queue.cc:237] T 00000000000000000000000000000000 P 306622a98948468a8dd16e5b1955a941 [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: "306622a98948468a8dd16e5b1955a941" member_type: VOTER }
I20260812 06:17:00.524523   915 sys_catalog.cc:565] T 00000000000000000000000000000000 P 306622a98948468a8dd16e5b1955a941 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:00.526876   921 sys_catalog.cc:455] T 00000000000000000000000000000000 P 306622a98948468a8dd16e5b1955a941 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 306622a98948468a8dd16e5b1955a941. Latest consensus state: current_term: 1 leader_uuid: "306622a98948468a8dd16e5b1955a941" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "306622a98948468a8dd16e5b1955a941" member_type: VOTER } }
I20260812 06:17:00.527050   921 sys_catalog.cc:458] T 00000000000000000000000000000000 P 306622a98948468a8dd16e5b1955a941 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:00.526847   920 sys_catalog.cc:455] T 00000000000000000000000000000000 P 306622a98948468a8dd16e5b1955a941 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "306622a98948468a8dd16e5b1955a941" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "306622a98948468a8dd16e5b1955a941" member_type: VOTER } }
I20260812 06:17:00.527351   920 sys_catalog.cc:458] T 00000000000000000000000000000000 P 306622a98948468a8dd16e5b1955a941 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:00.527637   840 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:17:00.530912   935 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 306622a98948468a8dd16e5b1955a941: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:17:00.531072   935 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:17:00.531153   932 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:00.532517   932 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:00.541271   932 catalog_manager.cc:1383] Generated new cluster ID: 53ec76af6c0f4746bfd53f999fd41ebe
I20260812 06:17:00.541394   932 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:00.559139   932 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:00.560297   932 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:00.569324   932 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 306622a98948468a8dd16e5b1955a941: Generated new TSK 0
I20260812 06:17:00.570250   932 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:00.594022   840 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:00.597764   941 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:00.597985   943 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:00.597817   940 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:00.599155   840 server_base.cc:1061] running on GCE node
I20260812 06:17:00.599447   840 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:00.599517   840 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:00.599546   840 hybrid_clock.cc:648] HybridClock initialized: now 1786515420599546 us; error 0 us; skew 500 ppm
I20260812 06:17:00.601051   840 webserver.cc:533] Webserver started at http://127.0.210.1:33933/ using document root <none> and password file <none>
I20260812 06:17:00.601296   840 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:00.601367   840 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:00.601464   840 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:00.602020   840 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420410567-840-0/minicluster-data/ts-0-root/instance:
uuid: "4c1c7a458e5a4407b32f768831ddec4b"
format_stamp: "Formatted at 2026-08-12 06:17:00 on dist-test-slave-77v9"
I20260812 06:17:00.605291   840 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.000s	sys 0.004s
I20260812 06:17:00.607481   948 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:00.608055   840 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.001s	sys 0.001s
I20260812 06:17:00.608208   840 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420410567-840-0/minicluster-data/ts-0-root
uuid: "4c1c7a458e5a4407b32f768831ddec4b"
format_stamp: "Formatted at 2026-08-12 06:17:00 on dist-test-slave-77v9"
I20260812 06:17:00.608359   840 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420410567-840-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420410567-840-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420410567-840-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:00.617653   840 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:00.618265   840 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:00.618969   840 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:00.619989   840 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:00.620074   840 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:00.620164   840 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:00.620209   840 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:00.628232   840 rpc_server.cc:307] RPC server started. Bound to: 127.0.210.1:35583
I20260812 06:17:00.628252  1024 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.0.210.1:35583 every 8 connection(s)
I20260812 06:17:00.641533  1025 heartbeater.cc:344] Connected to a master server at 127.0.210.62:32895
I20260812 06:17:00.642004  1025 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:00.642609  1025 heartbeater.cc:507] Master 127.0.210.62:32895 requested a full tablet report, sending...
I20260812 06:17:00.644454   874 ts_manager.cc:194] Registered new tserver with Master: 4c1c7a458e5a4407b32f768831ddec4b (127.0.210.1:35583)
I20260812 06:17:00.645262   840 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.016267937s
I20260812 06:17:00.645905   874 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:60158
I20260812 06:17:00.660912   874 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:60172:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:17:00.679018   981 tablet_service.cc:1511] Processing CreateTablet for tablet ed8b5c2d6fd4485e989d038cd7f91258 (DEFAULT_TABLE table=heavy-update-compaction-test [id=68dee87c66d548faa33d2559af3ddb1b]), partition=
I20260812 06:17:00.679627   981 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet ed8b5c2d6fd4485e989d038cd7f91258. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:00.682812  1037 tablet_bootstrap.cc:492] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b: Bootstrap starting.
I20260812 06:17:00.684115  1037 tablet_bootstrap.cc:654] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:00.685721  1037 tablet_bootstrap.cc:492] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b: No bootstrap required, opened a new log
I20260812 06:17:00.685896  1037 ts_tablet_manager.cc:1403] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b: Time spent bootstrapping tablet: real 0.003s	user 0.000s	sys 0.002s
I20260812 06:17:00.686441  1037 raft_consensus.cc:359] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4c1c7a458e5a4407b32f768831ddec4b" member_type: VOTER last_known_addr { host: "127.0.210.1" port: 35583 } }
I20260812 06:17:00.686622  1037 raft_consensus.cc:385] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:00.686663  1037 raft_consensus.cc:740] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 4c1c7a458e5a4407b32f768831ddec4b, State: Initialized, Role: FOLLOWER
I20260812 06:17:00.686961  1037 consensus_queue.cc:260] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b [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: "4c1c7a458e5a4407b32f768831ddec4b" member_type: VOTER last_known_addr { host: "127.0.210.1" port: 35583 } }
I20260812 06:17:00.687088  1037 raft_consensus.cc:399] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:00.687201  1037 raft_consensus.cc:493] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:00.687296  1037 raft_consensus.cc:3060] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:00.688333  1037 raft_consensus.cc:515] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4c1c7a458e5a4407b32f768831ddec4b" member_type: VOTER last_known_addr { host: "127.0.210.1" port: 35583 } }
I20260812 06:17:00.688529  1037 leader_election.cc:304] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b [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: 4c1c7a458e5a4407b32f768831ddec4b; no voters: 
I20260812 06:17:00.688863  1037 leader_election.cc:290] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:00.688989  1039 raft_consensus.cc:2804] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:00.689276  1039 raft_consensus.cc:697] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b [term 1 LEADER]: Becoming Leader. State: Replica: 4c1c7a458e5a4407b32f768831ddec4b, State: Running, Role: LEADER
I20260812 06:17:00.689289  1037 ts_tablet_manager.cc:1434] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:17:00.689601  1025 heartbeater.cc:499] Master 127.0.210.62:32895 was elected leader, sending a full tablet report...
I20260812 06:17:00.689554  1039 consensus_queue.cc:237] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b [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: "4c1c7a458e5a4407b32f768831ddec4b" member_type: VOTER last_known_addr { host: "127.0.210.1" port: 35583 } }
I20260812 06:17:00.693886   874 catalog_manager.cc:5719] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b reported cstate change: term changed from 0 to 1, leader changed from <none> to 4c1c7a458e5a4407b32f768831ddec4b (127.0.210.1). New cstate: current_term: 1 leader_uuid: "4c1c7a458e5a4407b32f768831ddec4b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4c1c7a458e5a4407b32f768831ddec4b" member_type: VOTER last_known_addr { host: "127.0.210.1" port: 35583 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:00.780680   840 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.078s	user 0.029s	sys 0.008s
I20260812 06:17:00.879769  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling FlushMRSOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=10.125253
I20260812 06:17:01.075975   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: FlushMRSOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.195s	user 0.129s	sys 0.048s Metrics: {"bytes_written":12307491,"cfile_init":1,"compiler_manager_pool.queue_time_us":277,"delete_count":0,"dirs.queue_time_us":173,"dirs.run_cpu_time_us":421,"dirs.run_wall_time_us":1664,"drs_written":1,"lbm_read_time_us":115,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40979,"lbm_writes_lt_1ms":557,"peak_mem_usage":0,"reinsert_count":0,"rows_written":102,"thread_start_us":187,"threads_started":1,"update_count":1500}
I20260812 06:17:01.078033  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling LogGCOp(ed8b5c2d6fd4485e989d038cd7f91258): free 8725963 bytes of WAL
I20260812 06:17:01.078527   954 log_reader.cc:385] T ed8b5c2d6fd4485e989d038cd7f91258: removed 1 log segments from log reader
I20260812 06:17:01.078625   954 log.cc:1079] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420410567-840-0/minicluster-data/ts-0-root/wals/ed8b5c2d6fd4485e989d038cd7f91258/wal-000000001 (ops 1-6)
I20260812 06:17:01.081653   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: LogGCOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.003s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:17:01.082295  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling UndoDeltaBlockGCOp(ed8b5c2d6fd4485e989d038cd7f91258): 8206537 bytes on disk
I20260812 06:17:01.083256   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: UndoDeltaBlockGCOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":137,"lbm_reads_lt_1ms":4}
I20260812 06:17:01.083923  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=2.188937
I20260812 06:17:01.112465   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.028s	user 0.012s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":8764,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:01.113477  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling MajorDeltaCompactionOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=1.000000
I20260812 06:17:01.287066   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: MajorDeltaCompactionOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.173s	user 0.132s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590348,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":139,"lbm_read_time_us":11821,"lbm_reads_lt_1ms":460,"lbm_write_time_us":31228,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":22784,"thread_start_us":275,"threads_started":5,"update_count":2000}
I20260812 06:17:01.287781  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=10.126437
I20260812 06:17:01.334879   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.047s	user 0.021s	sys 0.024s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":20839,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:01.335525  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=2.188937
I20260812 06:17:01.350734   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5613,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:01.351328  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling MajorDeltaCompactionOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=1.000000
I20260812 06:17:01.535503   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: MajorDeltaCompactionOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.184s	user 0.123s	sys 0.061s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590350,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":481,"lbm_read_time_us":14809,"lbm_reads_lt_1ms":472,"lbm_write_time_us":36136,"lbm_writes_lt_1ms":443,"mutex_wait_us":1,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4992,"update_count":2000}
I20260812 06:17:01.536193  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=11.118625
I20260812 06:17:01.591244   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.055s	user 0.026s	sys 0.027s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":20506,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:01.592761  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=2.188937
I20260812 06:17:01.608476   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5850,"lbm_writes_lt_1ms":93,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":450}
I20260812 06:17:01.609355  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling MajorDeltaCompactionOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=1.000000
I20260812 06:17:01.786003   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: MajorDeltaCompactionOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.176s	user 0.120s	sys 0.052s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590339,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":408,"lbm_read_time_us":11505,"lbm_reads_lt_1ms":468,"lbm_write_time_us":29293,"lbm_writes_lt_1ms":443,"mutex_wait_us":45,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:01.786813  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=11.118625
I20260812 06:17:01.834013   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.047s	user 0.038s	sys 0.008s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":20459,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:01.834617  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=2.188937
I20260812 06:17:01.863147   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.028s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5262,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:01.863857  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=2.188937
I20260812 06:17:01.877954   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.014s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5114,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:01.878854  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling MajorDeltaCompactionOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=1.000000
I20260812 06:17:02.067021   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: MajorDeltaCompactionOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.188s	user 0.168s	sys 0.019s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24692869,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1298,"lbm_read_time_us":12891,"lbm_reads_lt_1ms":573,"lbm_write_time_us":40883,"lbm_writes_lt_1ms":543,"mutex_wait_us":90,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":32768,"update_count":2500}
I20260812 06:17:02.067766  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=10.126437
I20260812 06:17:02.130798   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.063s	user 0.030s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":23594,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:02.131619  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=2.188937
I20260812 06:17:02.151607   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.020s	user 0.002s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5289,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:02.152336  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling MajorDeltaCompactionOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=1.000000
I20260812 06:17:02.304378   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: MajorDeltaCompactionOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.152s	user 0.116s	sys 0.035s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590347,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":793,"lbm_read_time_us":8911,"lbm_reads_lt_1ms":464,"lbm_write_time_us":31737,"lbm_writes_lt_1ms":443,"mutex_wait_us":56,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":23168,"update_count":2000}
I20260812 06:17:02.305653  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=10.126437
I20260812 06:17:02.351373   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.045s	user 0.019s	sys 0.024s Metrics: {"bytes_written":12307577,"delete_count":0,"lbm_write_time_us":20137,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:02.352073  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=2.188937
I20260812 06:17:02.374146   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.022s	user 0.016s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":8550,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:02.374709  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling MajorDeltaCompactionOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=1.000000
I20260812 06:17:02.591845   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: MajorDeltaCompactionOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.217s	user 0.178s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590434,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":99,"lbm_read_time_us":13130,"lbm_reads_lt_1ms":464,"lbm_write_time_us":46694,"lbm_writes_lt_1ms":443,"mutex_wait_us":28,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8576,"update_count":2000}
I20260812 06:17:02.592542  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=10.126437
I20260812 06:17:02.670676   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.078s	user 0.025s	sys 0.036s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":22640,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:02.671643  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=2.188937
I20260812 06:17:02.693183   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.021s	user 0.010s	sys 0.011s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":7787,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:02.694676  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling FlushMRSOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=1.000000
I20260812 06:17:02.764979   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: FlushMRSOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.070s	user 0.047s	sys 0.004s Metrics: {"bytes_written":1193504,"cfile_init":1,"dirs.queue_time_us":108,"dirs.run_cpu_time_us":311,"dirs.run_wall_time_us":3419,"drs_written":1,"lbm_read_time_us":76,"lbm_reads_lt_1ms":4,"lbm_write_time_us":3632,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:02.766079  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling LogGCOp(ed8b5c2d6fd4485e989d038cd7f91258): free 123804183 bytes of WAL
I20260812 06:17:02.766448   954 log_reader.cc:385] T ed8b5c2d6fd4485e989d038cd7f91258: removed 12 log segments from log reader
I20260812 06:17:02.766515   954 log.cc:1079] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420410567-840-0/minicluster-data/ts-0-root/wals/ed8b5c2d6fd4485e989d038cd7f91258/wal-000000002 (ops 7-10)
I20260812 06:17:02.767027   954 log.cc:1079] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420410567-840-0/minicluster-data/ts-0-root/wals/ed8b5c2d6fd4485e989d038cd7f91258/wal-000000003 (ops 11-15)
I20260812 06:17:02.767108   954 log.cc:1079] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420410567-840-0/minicluster-data/ts-0-root/wals/ed8b5c2d6fd4485e989d038cd7f91258/wal-000000004 (ops 16-20)
I20260812 06:17:02.767138   954 log.cc:1079] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420410567-840-0/minicluster-data/ts-0-root/wals/ed8b5c2d6fd4485e989d038cd7f91258/wal-000000005 (ops 21-24)
I20260812 06:17:02.767181   954 log.cc:1079] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420410567-840-0/minicluster-data/ts-0-root/wals/ed8b5c2d6fd4485e989d038cd7f91258/wal-000000006 (ops 25-29)
I20260812 06:17:02.767220   954 log.cc:1079] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420410567-840-0/minicluster-data/ts-0-root/wals/ed8b5c2d6fd4485e989d038cd7f91258/wal-000000007 (ops 30-34)
I20260812 06:17:02.767409   954 log.cc:1079] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420410567-840-0/minicluster-data/ts-0-root/wals/ed8b5c2d6fd4485e989d038cd7f91258/wal-000000008 (ops 35-39)
I20260812 06:17:02.767496   954 log.cc:1079] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420410567-840-0/minicluster-data/ts-0-root/wals/ed8b5c2d6fd4485e989d038cd7f91258/wal-000000009 (ops 40-44)
I20260812 06:17:02.767529   954 log.cc:1079] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420410567-840-0/minicluster-data/ts-0-root/wals/ed8b5c2d6fd4485e989d038cd7f91258/wal-000000010 (ops 45-49)
I20260812 06:17:02.767575   954 log.cc:1079] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420410567-840-0/minicluster-data/ts-0-root/wals/ed8b5c2d6fd4485e989d038cd7f91258/wal-000000011 (ops 50-54)
I20260812 06:17:02.767622   954 log.cc:1079] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420410567-840-0/minicluster-data/ts-0-root/wals/ed8b5c2d6fd4485e989d038cd7f91258/wal-000000012 (ops 55-59)
I20260812 06:17:02.767650   954 log.cc:1079] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420410567-840-0/minicluster-data/ts-0-root/wals/ed8b5c2d6fd4485e989d038cd7f91258/wal-000000013 (ops 60-64)
I20260812 06:17:02.809185   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: LogGCOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.043s	user 0.007s	sys 0.035s Metrics: {}
I20260812 06:17:02.809856  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=2.188937
I20260812 06:17:02.847419   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.037s	user 0.003s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7876,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:02.848049  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=2.188937
I20260812 06:17:02.866397   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.018s	user 0.005s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7646,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:02.867044  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling MajorDeltaCompactionOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=1.000000
I20260812 06:17:03.169628   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: MajorDeltaCompactionOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.302s	user 0.189s	sys 0.096s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28795408,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":289,"lbm_read_time_us":21538,"lbm_reads_lt_1ms":674,"lbm_write_time_us":50233,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":642,"mutex_wait_us":58,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1280,"thread_start_us":422,"threads_started":6,"update_count":3000}
I20260812 06:17:03.171813  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=14.095187
I20260812 06:17:03.246417   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.074s	user 0.049s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":28437,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2000}
I20260812 06:17:03.247442  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling UndoDeltaBlockGCOp(ed8b5c2d6fd4485e989d038cd7f91258): 463 bytes on disk
I20260812 06:17:03.247987   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: UndoDeltaBlockGCOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4}
I20260812 06:17:03.248621  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling MajorDeltaCompactionOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=1.000000
I20260812 06:17:03.435746   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: MajorDeltaCompactionOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.187s	user 0.126s	sys 0.052s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20590227,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":8353,"dirs.run_cpu_time_us":3525,"dirs.run_wall_time_us":27264,"lbm_read_time_us":10257,"lbm_reads_lt_1ms":463,"lbm_write_time_us":29179,"lbm_writes_lt_1ms":443,"mutex_wait_us":7315,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":20480,"update_count":2000}
I20260812 06:17:03.436671  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=10.126437
I20260812 06:17:03.504012   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.067s	user 0.034s	sys 0.022s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":24733,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:03.504717  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=2.188937
I20260812 06:17:03.526427   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.021s	user 0.012s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7343,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:03.528116  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling MajorDeltaCompactionOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=1.000000
I20260812 06:17:03.728160   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: MajorDeltaCompactionOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.199s	user 0.138s	sys 0.061s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590349,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":657,"lbm_read_time_us":15177,"lbm_reads_lt_1ms":472,"lbm_write_time_us":38489,"lbm_writes_lt_1ms":443,"mutex_wait_us":24,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13696,"thread_start_us":119,"threads_started":1,"update_count":2000}
I20260812 06:17:03.735387  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=10.126437
I20260812 06:17:03.798127   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.062s	user 0.030s	sys 0.022s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":22633,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:03.798964  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=2.188937
I20260812 06:17:03.820523   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.021s	user 0.015s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":8344,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:03.821237  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling MajorDeltaCompactionOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=1.000000
I20260812 06:17:04.004462   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: MajorDeltaCompactionOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.183s	user 0.156s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590347,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1984,"lbm_read_time_us":12220,"lbm_reads_lt_1ms":472,"lbm_write_time_us":34935,"lbm_writes_lt_1ms":443,"mutex_wait_us":1769,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5888,"update_count":2000}
I20260812 06:17:04.005303  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=10.126437
I20260812 06:17:04.065335   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.060s	user 0.032s	sys 0.025s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":23577,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:04.066151  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=2.188937
I20260812 06:17:04.088559   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.022s	user 0.018s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7720,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:04.089349  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling MajorDeltaCompactionOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=1.000000
I20260812 06:17:04.261020   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: MajorDeltaCompactionOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.171s	user 0.139s	sys 0.031s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590347,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1293,"lbm_read_time_us":12196,"lbm_reads_lt_1ms":464,"lbm_write_time_us":32934,"lbm_writes_lt_1ms":443,"mutex_wait_us":102,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":23040,"update_count":2000}
I20260812 06:17:04.262116  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=10.126437
I20260812 06:17:04.329174   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.067s	user 0.034s	sys 0.031s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":23225,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:04.330364  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=2.188937
I20260812 06:17:04.353012   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.022s	user 0.018s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":8398,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:04.353796  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling MajorDeltaCompactionOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=1.000000
I20260812 06:17:04.556219   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: MajorDeltaCompactionOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.202s	user 0.137s	sys 0.064s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590348,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":644,"lbm_read_time_us":14920,"lbm_reads_lt_1ms":472,"lbm_write_time_us":33076,"lbm_writes_lt_1ms":443,"mutex_wait_us":31,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":25728,"update_count":2000}
I20260812 06:17:04.557426  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=10.126437
I20260812 06:17:04.608037   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.048s	user 0.029s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":21458,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:04.608716  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=2.188937
I20260812 06:17:04.625170   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.016s	user 0.011s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6308,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:04.627264  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling MajorDeltaCompactionOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=1.000000
I20260812 06:17:04.819120   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: MajorDeltaCompactionOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.192s	user 0.161s	sys 0.023s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590347,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":374,"lbm_read_time_us":11756,"lbm_reads_lt_1ms":472,"lbm_write_time_us":38010,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":26368,"update_count":2000}
I20260812 06:17:04.819888  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=14.095187
I20260812 06:17:04.921520   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.101s	user 0.065s	sys 0.035s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":44631,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:04.923218  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=3.181125
I20260812 06:17:04.958215   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.034s	user 0.021s	sys 0.011s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":14046,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:04.959570  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=2.188937
I20260812 06:17:04.987964   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.028s	user 0.013s	sys 0.011s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":9533,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:04.988902  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling FlushMRSOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=1.000000
I20260812 06:17:05.074115   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: FlushMRSOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.085s	user 0.051s	sys 0.003s Metrics: {"bytes_written":1357580,"cfile_init":1,"dirs.queue_time_us":111,"dirs.run_cpu_time_us":364,"dirs.run_wall_time_us":2688,"drs_written":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2678,"lbm_writes_lt_1ms":44,"peak_mem_usage":0,"rows_written":33}
I20260812 06:17:05.075889  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling LogGCOp(ed8b5c2d6fd4485e989d038cd7f91258): free 133477420 bytes of WAL
I20260812 06:17:05.076426   954 log_reader.cc:385] T ed8b5c2d6fd4485e989d038cd7f91258: removed 13 log segments from log reader
I20260812 06:17:05.076552   954 log.cc:1079] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420410567-840-0/minicluster-data/ts-0-root/wals/ed8b5c2d6fd4485e989d038cd7f91258/wal-000000014 (ops 65-69)
I20260812 06:17:05.076601   954 log.cc:1079] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420410567-840-0/minicluster-data/ts-0-root/wals/ed8b5c2d6fd4485e989d038cd7f91258/wal-000000015 (ops 70-74)
I20260812 06:17:05.076646   954 log.cc:1079] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420410567-840-0/minicluster-data/ts-0-root/wals/ed8b5c2d6fd4485e989d038cd7f91258/wal-000000016 (ops 75-79)
I20260812 06:17:05.076733   954 log.cc:1079] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420410567-840-0/minicluster-data/ts-0-root/wals/ed8b5c2d6fd4485e989d038cd7f91258/wal-000000017 (ops 80-84)
I20260812 06:17:05.076773   954 log.cc:1079] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420410567-840-0/minicluster-data/ts-0-root/wals/ed8b5c2d6fd4485e989d038cd7f91258/wal-000000018 (ops 85-89)
I20260812 06:17:05.076798   954 log.cc:1079] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420410567-840-0/minicluster-data/ts-0-root/wals/ed8b5c2d6fd4485e989d038cd7f91258/wal-000000019 (ops 90-94)
I20260812 06:17:05.076869   954 log.cc:1079] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420410567-840-0/minicluster-data/ts-0-root/wals/ed8b5c2d6fd4485e989d038cd7f91258/wal-000000020 (ops 95-99)
I20260812 06:17:05.077119   954 log.cc:1079] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420410567-840-0/minicluster-data/ts-0-root/wals/ed8b5c2d6fd4485e989d038cd7f91258/wal-000000021 (ops 100-104)
I20260812 06:17:05.077273   954 log.cc:1079] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420410567-840-0/minicluster-data/ts-0-root/wals/ed8b5c2d6fd4485e989d038cd7f91258/wal-000000022 (ops 105-109)
I20260812 06:17:05.077303   954 log.cc:1079] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420410567-840-0/minicluster-data/ts-0-root/wals/ed8b5c2d6fd4485e989d038cd7f91258/wal-000000023 (ops 110-114)
I20260812 06:17:05.077327   954 log.cc:1079] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420410567-840-0/minicluster-data/ts-0-root/wals/ed8b5c2d6fd4485e989d038cd7f91258/wal-000000024 (ops 115-119)
I20260812 06:17:05.077430   954 log.cc:1079] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420410567-840-0/minicluster-data/ts-0-root/wals/ed8b5c2d6fd4485e989d038cd7f91258/wal-000000025 (ops 120-124)
I20260812 06:17:05.077471   954 log.cc:1079] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420410567-840-0/minicluster-data/ts-0-root/wals/ed8b5c2d6fd4485e989d038cd7f91258/wal-000000026 (ops 125-129)
I20260812 06:17:05.119220   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: LogGCOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.043s	user 0.000s	sys 0.040s Metrics: {}
I20260812 06:17:05.119964  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=7.149875
I20260812 06:17:05.153925   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.034s	user 0.016s	sys 0.016s Metrics: {"bytes_written":8984540,"delete_count":0,"lbm_write_time_us":15202,"lbm_writes_lt_1ms":222,"reinsert_count":0,"update_count":1095}
I20260812 06:17:05.154664  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling UndoDeltaBlockGCOp(ed8b5c2d6fd4485e989d038cd7f91258): 508 bytes on disk
I20260812 06:17:05.156127   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: UndoDeltaBlockGCOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":688,"lbm_reads_lt_1ms":4}
I20260812 06:17:05.157116  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=2.188937
I20260812 06:17:05.189874   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.033s	user 0.006s	sys 0.008s Metrics: {"bytes_written":3323180,"delete_count":0,"lbm_write_time_us":5459,"lbm_writes_lt_1ms":84,"reinsert_count":0,"update_count":405}
I20260812 06:17:05.190754  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=2.188937
I20260812 06:17:05.205847   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.015s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5851,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:05.206588  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling MajorDeltaCompactionOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=1.000000
I20260812 06:17:05.578894   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: MajorDeltaCompactionOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.372s	user 0.240s	sys 0.131s Metrics: {"cfile_cache_miss":1036,"cfile_cache_miss_bytes":45205271,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":6,"delta_iterators_relevant":6,"dirs.queue_time_us":302,"lbm_read_time_us":24818,"lbm_reads_lt_1ms":1076,"lbm_write_time_us":76178,"lbm_writes_lt_1ms":1043,"peak_mem_usage":125248760,"reinsert_count":0,"spinlock_wait_cycles":30336,"thread_start_us":979,"threads_started":7,"update_count":5000}
I20260812 06:17:05.579700  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=18.063937
I20260812 06:17:05.691869   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.112s	user 0.049s	sys 0.047s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":48420,"lbm_writes_1-10_ms":5,"lbm_writes_lt_1ms":498,"reinsert_count":0,"update_count":2500}
I20260812 06:17:05.692795  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=4.173312
I20260812 06:17:05.716871   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.024s	user 0.005s	sys 0.016s Metrics: {"bytes_written":6030801,"delete_count":0,"lbm_write_time_us":10129,"lbm_writes_lt_1ms":150,"reinsert_count":0,"update_count":735}
I20260812 06:17:05.717729  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=1.196750
I20260812 06:17:05.736755   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.019s	user 0.007s	sys 0.005s Metrics: {"bytes_written":2174479,"delete_count":0,"lbm_write_time_us":4879,"lbm_writes_lt_1ms":56,"reinsert_count":0,"update_count":265}
I20260812 06:17:05.737484  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling MajorDeltaCompactionOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=1.000000
I20260812 06:17:06.020414   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: MajorDeltaCompactionOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.283s	user 0.176s	sys 0.102s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32897661,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1313,"lbm_read_time_us":20397,"lbm_reads_lt_1ms":765,"lbm_write_time_us":50471,"lbm_writes_lt_1ms":743,"mutex_wait_us":407,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":20992,"update_count":3500}
I20260812 06:17:06.021454  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=15.087375
I20260812 06:17:06.098495   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.077s	user 0.049s	sys 0.017s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":31399,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:17:06.099354  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=2.188937
I20260812 06:17:06.124734   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.025s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6339,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:06.125626  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=2.188937
I20260812 06:17:06.143004   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.017s	user 0.010s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6039,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:06.143651  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling MajorDeltaCompactionOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=1.000000
I20260812 06:17:06.377334   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: MajorDeltaCompactionOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.233s	user 0.164s	sys 0.064s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28795277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":3166,"lbm_read_time_us":18283,"lbm_reads_lt_1ms":673,"lbm_write_time_us":42751,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":3000}
I20260812 06:17:06.378065  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=10.126437
I20260812 06:17:06.444041   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.066s	user 0.023s	sys 0.037s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":28783,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:06.444749  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=2.188937
I20260812 06:17:06.478466   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.033s	user 0.022s	sys 0.009s Metrics: {"bytes_written":4102660,"delete_count":0,"lbm_write_time_us":12411,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:06.479241  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling MajorDeltaCompactionOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=1.000000
I20260812 06:17:06.689774   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: MajorDeltaCompactionOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.210s	user 0.159s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590349,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1263,"lbm_read_time_us":18420,"lbm_reads_lt_1ms":472,"lbm_write_time_us":38668,"lbm_writes_lt_1ms":443,"mutex_wait_us":415,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":36224,"update_count":2000}
I20260812 06:17:06.690887  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=7.149875
I20260812 06:17:06.751883   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.061s	user 0.030s	sys 0.027s Metrics: {"bytes_written":8656348,"delete_count":0,"lbm_write_time_us":16559,"lbm_writes_lt_1ms":214,"reinsert_count":0,"update_count":1055}
I20260812 06:17:06.752636  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=2.188937
I20260812 06:17:06.773129   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.020s	user 0.012s	sys 0.008s Metrics: {"bytes_written":3651380,"delete_count":0,"lbm_write_time_us":7284,"lbm_writes_lt_1ms":92,"reinsert_count":0,"update_count":445}
I20260812 06:17:06.774853  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling MajorDeltaCompactionOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=1.000000
I20260812 06:17:07.047379   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: MajorDeltaCompactionOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.272s	user 0.196s	sys 0.068s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16487926,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":478,"lbm_read_time_us":15428,"lbm_reads_lt_1ms":372,"lbm_write_time_us":31239,"lbm_writes_lt_1ms":343,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":5504,"update_count":1500}
I20260812 06:17:07.052135  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=15.087375
I20260812 06:17:07.115681   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.063s	user 0.040s	sys 0.020s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":28113,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":411,"reinsert_count":0,"update_count":2050}
I20260812 06:17:07.116546  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=2.188937
I20260812 06:17:07.142803   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.026s	user 0.016s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6981,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:07.143613  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling FlushMRSOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=1.000000
I20260812 06:17:07.198112   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: FlushMRSOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.054s	user 0.038s	sys 0.004s Metrics: {"bytes_written":1193507,"cfile_init":1,"dirs.queue_time_us":102,"dirs.run_cpu_time_us":378,"dirs.run_wall_time_us":3356,"drs_written":1,"lbm_read_time_us":140,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1902,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:07.200112  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling UndoDeltaBlockGCOp(ed8b5c2d6fd4485e989d038cd7f91258): 463 bytes on disk
I20260812 06:17:07.200863   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: UndoDeltaBlockGCOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":130,"lbm_reads_lt_1ms":4}
I20260812 06:17:07.202020  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=3.181125
I20260812 06:17:07.224949   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.022s	user 0.020s	sys 0.002s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":7821,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:07.225916  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling LogGCOp(ed8b5c2d6fd4485e989d038cd7f91258): free 120553658 bytes of WAL
I20260812 06:17:07.226269   954 log_reader.cc:385] T ed8b5c2d6fd4485e989d038cd7f91258: removed 12 log segments from log reader
I20260812 06:17:07.226327   954 log.cc:1079] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420410567-840-0/minicluster-data/ts-0-root/wals/ed8b5c2d6fd4485e989d038cd7f91258/wal-000000027 (ops 130-134)
I20260812 06:17:07.226388   954 log.cc:1079] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420410567-840-0/minicluster-data/ts-0-root/wals/ed8b5c2d6fd4485e989d038cd7f91258/wal-000000028 (ops 135-139)
I20260812 06:17:07.226435   954 log.cc:1079] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420410567-840-0/minicluster-data/ts-0-root/wals/ed8b5c2d6fd4485e989d038cd7f91258/wal-000000029 (ops 140-144)
I20260812 06:17:07.226483   954 log.cc:1079] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420410567-840-0/minicluster-data/ts-0-root/wals/ed8b5c2d6fd4485e989d038cd7f91258/wal-000000030 (ops 145-149)
I20260812 06:17:07.226549   954 log.cc:1079] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420410567-840-0/minicluster-data/ts-0-root/wals/ed8b5c2d6fd4485e989d038cd7f91258/wal-000000031 (ops 150-154)
I20260812 06:17:07.226655   954 log.cc:1079] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420410567-840-0/minicluster-data/ts-0-root/wals/ed8b5c2d6fd4485e989d038cd7f91258/wal-000000032 (ops 155-159)
I20260812 06:17:07.226706   954 log.cc:1079] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420410567-840-0/minicluster-data/ts-0-root/wals/ed8b5c2d6fd4485e989d038cd7f91258/wal-000000033 (ops 160-164)
I20260812 06:17:07.226751   954 log.cc:1079] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420410567-840-0/minicluster-data/ts-0-root/wals/ed8b5c2d6fd4485e989d038cd7f91258/wal-000000034 (ops 165-168)
I20260812 06:17:07.226796   954 log.cc:1079] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420410567-840-0/minicluster-data/ts-0-root/wals/ed8b5c2d6fd4485e989d038cd7f91258/wal-000000035 (ops 169-173)
I20260812 06:17:07.226840   954 log.cc:1079] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420410567-840-0/minicluster-data/ts-0-root/wals/ed8b5c2d6fd4485e989d038cd7f91258/wal-000000036 (ops 174-178)
I20260812 06:17:07.226886   954 log.cc:1079] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420410567-840-0/minicluster-data/ts-0-root/wals/ed8b5c2d6fd4485e989d038cd7f91258/wal-000000037 (ops 179-182)
I20260812 06:17:07.226930   954 log.cc:1079] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515420410567-840-0/minicluster-data/ts-0-root/wals/ed8b5c2d6fd4485e989d038cd7f91258/wal-000000038 (ops 183-187)
I20260812 06:17:07.263309   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: LogGCOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.037s	user 0.000s	sys 0.032s Metrics: {}
I20260812 06:17:07.263962  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=2.188937
I20260812 06:17:07.295548   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.031s	user 0.010s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7499,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:07.296315  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=2.188937
I20260812 06:17:07.312671   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.016s	user 0.010s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6086,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:07.313337  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling MajorDeltaCompactionOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=1.000000
I20260812 06:17:07.726410   840 heavy-update-compaction-itest.cc:229] Time spent updating: real 6.946s	user 2.421s	sys 0.178s
I20260812 06:17:07.744908   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: MajorDeltaCompactionOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.431s	user 0.284s	sys 0.123s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37000328,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":944,"lbm_read_time_us":32259,"lbm_reads_1-10_ms":1,"lbm_reads_lt_1ms":874,"lbm_write_time_us":78061,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":841,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":2944,"thread_start_us":512,"threads_started":7,"update_count":4000}
I20260812 06:17:07.745843  1026 maintenance_manager.cc:419] P 4c1c7a458e5a4407b32f768831ddec4b: Scheduling FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258): perf score=18.063937
I20260812 06:17:07.799696   840 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.073s	user 0.003s	sys 0.000s
I20260812 06:17:07.803440   840 tablet_server.cc:179] TabletServer@127.0.210.1:0 shutting down...
I20260812 06:17:07.821705   954 maintenance_manager.cc:643] P 4c1c7a458e5a4407b32f768831ddec4b: FlushDeltaMemStoresOp(ed8b5c2d6fd4485e989d038cd7f91258) complete. Timing: real 0.076s	user 0.056s	sys 0.019s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":34260,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:07.822371   840 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:07.822968   840 tablet_replica.cc:333] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b: stopping tablet replica
I20260812 06:17:07.823199   840 raft_consensus.cc:2243] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:07.823422   840 raft_consensus.cc:2272] T ed8b5c2d6fd4485e989d038cd7f91258 P 4c1c7a458e5a4407b32f768831ddec4b [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:07.843128   840 tablet_server.cc:196] TabletServer@127.0.210.1:0 shutdown complete.
I20260812 06:17:07.849956   840 master.cc:562] Master@127.0.210.62:32895 shutting down...
I20260812 06:17:07.856388   840 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 306622a98948468a8dd16e5b1955a941 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:07.856666   840 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 306622a98948468a8dd16e5b1955a941 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:07.856774   840 tablet_replica.cc:333] T 00000000000000000000000000000000 P 306622a98948468a8dd16e5b1955a941: stopping tablet replica
I20260812 06:17:07.870990   840 master.cc:584] Master@127.0.210.62:32895 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (7561 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:07.985091   840 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.0.210.62:43367
I20260812 06:17:07.985571   840 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:07.988638  1087 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:07.988662  1085 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:07.989030   840 server_base.cc:1061] running on GCE node
W20260812 06:17:07.988662  1084 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:07.989670   840 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:07.989784   840 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:07.989812   840 hybrid_clock.cc:648] HybridClock initialized: now 1786515427989811 us; error 0 us; skew 500 ppm
I20260812 06:17:07.990888   840 webserver.cc:533] Webserver started at http://127.0.210.62:43565/ using document root <none> and password file <none>
I20260812 06:17:07.991137   840 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:07.991226   840 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:07.991353   840 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:07.991904   840 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420410567-840-0/minicluster-data/master-0-root/instance:
uuid: "de231d8361ae48239f6e649baceb2b1b"
format_stamp: "Formatted at 2026-08-12 06:17:07 on dist-test-slave-77v9"
I20260812 06:17:07.994418   840 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.003s
I20260812 06:17:07.995903  1095 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:07.996555   840 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.001s
I20260812 06:17:07.996937   840 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420410567-840-0/minicluster-data/master-0-root
uuid: "de231d8361ae48239f6e649baceb2b1b"
format_stamp: "Formatted at 2026-08-12 06:17:07 on dist-test-slave-77v9"
I20260812 06:17:07.997110   840 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420410567-840-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420410567-840-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420410567-840-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:08.013473   840 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:08.014106   840 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:08.019731   840 rpc_server.cc:307] RPC server started. Bound to: 127.0.210.62:43367
I20260812 06:17:08.023366  1155 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.0.210.62:43367 every 8 connection(s)
I20260812 06:17:08.024004  1156 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:08.038200  1156 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P de231d8361ae48239f6e649baceb2b1b: Bootstrap starting.
I20260812 06:17:08.039332  1156 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P de231d8361ae48239f6e649baceb2b1b: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:08.041256  1156 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P de231d8361ae48239f6e649baceb2b1b: No bootstrap required, opened a new log
I20260812 06:17:08.041864  1156 raft_consensus.cc:359] T 00000000000000000000000000000000 P de231d8361ae48239f6e649baceb2b1b [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "de231d8361ae48239f6e649baceb2b1b" member_type: VOTER }
I20260812 06:17:08.041983  1156 raft_consensus.cc:385] T 00000000000000000000000000000000 P de231d8361ae48239f6e649baceb2b1b [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:08.042011  1156 raft_consensus.cc:740] T 00000000000000000000000000000000 P de231d8361ae48239f6e649baceb2b1b [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: de231d8361ae48239f6e649baceb2b1b, State: Initialized, Role: FOLLOWER
I20260812 06:17:08.042251  1156 consensus_queue.cc:260] T 00000000000000000000000000000000 P de231d8361ae48239f6e649baceb2b1b [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: "de231d8361ae48239f6e649baceb2b1b" member_type: VOTER }
I20260812 06:17:08.042366  1156 raft_consensus.cc:399] T 00000000000000000000000000000000 P de231d8361ae48239f6e649baceb2b1b [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:08.042421  1156 raft_consensus.cc:493] T 00000000000000000000000000000000 P de231d8361ae48239f6e649baceb2b1b [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:08.042497  1156 raft_consensus.cc:3060] T 00000000000000000000000000000000 P de231d8361ae48239f6e649baceb2b1b [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:08.043469  1156 raft_consensus.cc:515] T 00000000000000000000000000000000 P de231d8361ae48239f6e649baceb2b1b [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "de231d8361ae48239f6e649baceb2b1b" member_type: VOTER }
I20260812 06:17:08.043668  1156 leader_election.cc:304] T 00000000000000000000000000000000 P de231d8361ae48239f6e649baceb2b1b [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: de231d8361ae48239f6e649baceb2b1b; no voters: 
I20260812 06:17:08.043996  1156 leader_election.cc:290] T 00000000000000000000000000000000 P de231d8361ae48239f6e649baceb2b1b [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:08.044174  1159 raft_consensus.cc:2804] T 00000000000000000000000000000000 P de231d8361ae48239f6e649baceb2b1b [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:08.044647  1156 sys_catalog.cc:565] T 00000000000000000000000000000000 P de231d8361ae48239f6e649baceb2b1b [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:08.044761  1159 raft_consensus.cc:697] T 00000000000000000000000000000000 P de231d8361ae48239f6e649baceb2b1b [term 1 LEADER]: Becoming Leader. State: Replica: de231d8361ae48239f6e649baceb2b1b, State: Running, Role: LEADER
I20260812 06:17:08.045006  1159 consensus_queue.cc:237] T 00000000000000000000000000000000 P de231d8361ae48239f6e649baceb2b1b [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: "de231d8361ae48239f6e649baceb2b1b" member_type: VOTER }
I20260812 06:17:08.045605  1162 sys_catalog.cc:455] T 00000000000000000000000000000000 P de231d8361ae48239f6e649baceb2b1b [sys.catalog]: SysCatalogTable state changed. Reason: New leader de231d8361ae48239f6e649baceb2b1b. Latest consensus state: current_term: 1 leader_uuid: "de231d8361ae48239f6e649baceb2b1b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "de231d8361ae48239f6e649baceb2b1b" member_type: VOTER } }
I20260812 06:17:08.045812  1162 sys_catalog.cc:458] T 00000000000000000000000000000000 P de231d8361ae48239f6e649baceb2b1b [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:08.046103  1161 sys_catalog.cc:455] T 00000000000000000000000000000000 P de231d8361ae48239f6e649baceb2b1b [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "de231d8361ae48239f6e649baceb2b1b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "de231d8361ae48239f6e649baceb2b1b" member_type: VOTER } }
I20260812 06:17:08.046643  1170 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:08.046716  1161 sys_catalog.cc:458] T 00000000000000000000000000000000 P de231d8361ae48239f6e649baceb2b1b [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:08.047732  1170 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:08.047961   840 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:08.050506  1170 catalog_manager.cc:1383] Generated new cluster ID: 89fefc64931643eb814259ecb9fe81f7
I20260812 06:17:08.050598  1170 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:08.062393  1170 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:08.063107  1170 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:08.075984  1170 catalog_manager.cc:6092] T 00000000000000000000000000000000 P de231d8361ae48239f6e649baceb2b1b: Generated new TSK 0
I20260812 06:17:08.076285  1170 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:08.081013   840 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:17:08.085688   840 server_base.cc:1061] running on GCE node
W20260812 06:17:08.085220  1180 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:08.085263  1183 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:08.085304  1181 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:08.086539   840 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:08.086606   840 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:08.086622   840 hybrid_clock.cc:648] HybridClock initialized: now 1786515428086623 us; error 0 us; skew 500 ppm
I20260812 06:17:08.087875   840 webserver.cc:533] Webserver started at http://127.0.210.1:44409/ using document root <none> and password file <none>
I20260812 06:17:08.088119   840 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:08.088181   840 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:08.088289   840 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:08.088726   840 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420410567-840-0/minicluster-data/ts-0-root/instance:
uuid: "5e7e53e1ec7f4611a13539ccef65b3b5"
format_stamp: "Formatted at 2026-08-12 06:17:08 on dist-test-slave-77v9"
I20260812 06:17:08.090668   840 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:17:08.092357  1189 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:08.093108   840 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:08.093248   840 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420410567-840-0/minicluster-data/ts-0-root
uuid: "5e7e53e1ec7f4611a13539ccef65b3b5"
format_stamp: "Formatted at 2026-08-12 06:17:08 on dist-test-slave-77v9"
I20260812 06:17:08.093369   840 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420410567-840-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420410567-840-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420410567-840-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:08.101930   840 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:08.102499   840 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:08.103050   840 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:08.103652   840 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:08.103725   840 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:08.103793   840 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:08.103832   840 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:08.109948   840 rpc_server.cc:307] RPC server started. Bound to: 127.0.210.1:38851
I20260812 06:17:08.110809  1264 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.0.210.1:38851 every 8 connection(s)
I20260812 06:17:08.118242  1265 heartbeater.cc:344] Connected to a master server at 127.0.210.62:43367
I20260812 06:17:08.118479  1265 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:08.118785  1265 heartbeater.cc:507] Master 127.0.210.62:43367 requested a full tablet report, sending...
I20260812 06:17:08.119733  1116 ts_manager.cc:194] Registered new tserver with Master: 5e7e53e1ec7f4611a13539ccef65b3b5 (127.0.210.1:38851)
I20260812 06:17:08.120529  1116 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:42546
I20260812 06:17:08.120644   840 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.009224389s
I20260812 06:17:08.133867  1116 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:42554:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:17:08.153680  1227 tablet_service.cc:1511] Processing CreateTablet for tablet f9a55047c427485bb1ced02738d2d47d (DEFAULT_TABLE table=heavy-update-compaction-test [id=732570ca3a3d45a09b304493cd967eb0]), partition=
I20260812 06:17:08.154094  1227 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet f9a55047c427485bb1ced02738d2d47d. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:08.158638  1278 tablet_bootstrap.cc:492] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5: Bootstrap starting.
I20260812 06:17:08.159857  1278 tablet_bootstrap.cc:654] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:08.161563  1278 tablet_bootstrap.cc:492] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5: No bootstrap required, opened a new log
I20260812 06:17:08.161729  1278 ts_tablet_manager.cc:1403] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:17:08.162395  1278 raft_consensus.cc:359] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5e7e53e1ec7f4611a13539ccef65b3b5" member_type: VOTER last_known_addr { host: "127.0.210.1" port: 38851 } }
I20260812 06:17:08.162590  1278 raft_consensus.cc:385] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:08.162678  1278 raft_consensus.cc:740] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 5e7e53e1ec7f4611a13539ccef65b3b5, State: Initialized, Role: FOLLOWER
I20260812 06:17:08.162900  1278 consensus_queue.cc:260] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5 [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: "5e7e53e1ec7f4611a13539ccef65b3b5" member_type: VOTER last_known_addr { host: "127.0.210.1" port: 38851 } }
I20260812 06:17:08.163064  1278 raft_consensus.cc:399] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:08.163160  1278 raft_consensus.cc:493] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:08.163275  1278 raft_consensus.cc:3060] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:08.164371  1278 raft_consensus.cc:515] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5e7e53e1ec7f4611a13539ccef65b3b5" member_type: VOTER last_known_addr { host: "127.0.210.1" port: 38851 } }
I20260812 06:17:08.164572  1278 leader_election.cc:304] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5 [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: 5e7e53e1ec7f4611a13539ccef65b3b5; no voters: 
I20260812 06:17:08.165155  1278 leader_election.cc:290] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:08.166173  1278 ts_tablet_manager.cc:1434] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5: Time spent starting tablet: real 0.004s	user 0.001s	sys 0.002s
I20260812 06:17:08.165235  1280 raft_consensus.cc:2804] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:08.166407  1265 heartbeater.cc:499] Master 127.0.210.62:43367 was elected leader, sending a full tablet report...
I20260812 06:17:08.166577  1280 raft_consensus.cc:697] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5 [term 1 LEADER]: Becoming Leader. State: Replica: 5e7e53e1ec7f4611a13539ccef65b3b5, State: Running, Role: LEADER
I20260812 06:17:08.166780  1280 consensus_queue.cc:237] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5 [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: "5e7e53e1ec7f4611a13539ccef65b3b5" member_type: VOTER last_known_addr { host: "127.0.210.1" port: 38851 } }
I20260812 06:17:08.168538  1116 catalog_manager.cc:5719] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5 reported cstate change: term changed from 0 to 1, leader changed from <none> to 5e7e53e1ec7f4611a13539ccef65b3b5 (127.0.210.1). New cstate: current_term: 1 leader_uuid: "5e7e53e1ec7f4611a13539ccef65b3b5" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5e7e53e1ec7f4611a13539ccef65b3b5" member_type: VOTER last_known_addr { host: "127.0.210.1" port: 38851 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:08.245883   840 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.068s	user 0.014s	sys 0.011s
I20260812 06:17:08.362143  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling FlushMRSOp(f9a55047c427485bb1ced02738d2d47d): perf score=10.125253
I20260812 06:17:08.499720  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: FlushMRSOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.137s	user 0.098s	sys 0.036s Metrics: {"bytes_written":8861464,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":112,"dirs.run_cpu_time_us":397,"dirs.run_wall_time_us":1483,"drs_written":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4,"lbm_write_time_us":27107,"lbm_writes_lt_1ms":473,"peak_mem_usage":0,"reinsert_count":0,"rows_written":102,"update_count":1080}
I20260812 06:17:08.500561  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling LogGCOp(f9a55047c427485bb1ced02738d2d47d): free 11976772 bytes of WAL
I20260812 06:17:08.500883  1196 log_reader.cc:385] T f9a55047c427485bb1ced02738d2d47d: removed 1 log segments from log reader
I20260812 06:17:08.500947  1196 log.cc:1079] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420410567-840-0/minicluster-data/ts-0-root/wals/f9a55047c427485bb1ced02738d2d47d/wal-000000001 (ops 1-6)
I20260812 06:17:08.504245  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: LogGCOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:17:08.504791  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling UndoDeltaBlockGCOp(f9a55047c427485bb1ced02738d2d47d): 8206538 bytes on disk
I20260812 06:17:08.505400  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: UndoDeltaBlockGCOp(f9a55047c427485bb1ced02738d2d47d) 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:17:08.505882  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d): perf score=2.188937
I20260812 06:17:08.520171  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.014s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3446258,"delete_count":0,"lbm_write_time_us":5264,"lbm_writes_lt_1ms":87,"reinsert_count":0,"update_count":420}
I20260812 06:17:08.520754  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling MajorDeltaCompactionOp(f9a55047c427485bb1ced02738d2d47d): perf score=1.000000
I20260812 06:17:08.680310  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: MajorDeltaCompactionOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.159s	user 0.102s	sys 0.057s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16487920,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":402,"lbm_read_time_us":12496,"lbm_reads_lt_1ms":368,"lbm_write_time_us":23947,"lbm_writes_lt_1ms":343,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":6400,"thread_start_us":361,"threads_started":5,"update_count":1500}
I20260812 06:17:08.681061  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d): perf score=10.126437
I20260812 06:17:08.734712  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.053s	user 0.032s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":21351,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":1500}
I20260812 06:17:08.735728  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling MajorDeltaCompactionOp(f9a55047c427485bb1ced02738d2d47d): perf score=1.000000
I20260812 06:17:08.880502  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: MajorDeltaCompactionOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.144s	user 0.120s	sys 0.023s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16487816,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":463,"lbm_read_time_us":9730,"lbm_reads_lt_1ms":363,"lbm_write_time_us":26398,"lbm_writes_lt_1ms":343,"mutex_wait_us":106,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":24704,"update_count":1500}
I20260812 06:17:08.881304  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d): perf score=10.126437
I20260812 06:17:08.945053  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.063s	user 0.056s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":27956,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:08.945787  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d): perf score=2.188937
I20260812 06:17:08.960896  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.015s	user 0.012s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5145,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:08.961512  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling MajorDeltaCompactionOp(f9a55047c427485bb1ced02738d2d47d): perf score=1.000000
I20260812 06:17:09.119426  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: MajorDeltaCompactionOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.158s	user 0.117s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590348,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1777,"lbm_read_time_us":10711,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29397,"lbm_writes_lt_1ms":443,"mutex_wait_us":57,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1152,"update_count":2000}
I20260812 06:17:09.120414  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d): perf score=10.126437
I20260812 06:17:09.182286  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.062s	user 0.021s	sys 0.031s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":17686,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:09.183387  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d): perf score=2.188937
I20260812 06:17:09.199350  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.016s	user 0.001s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6309,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:09.199939  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling MajorDeltaCompactionOp(f9a55047c427485bb1ced02738d2d47d): perf score=1.000000
I20260812 06:17:09.388087  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: MajorDeltaCompactionOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.188s	user 0.131s	sys 0.056s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590346,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1447,"lbm_read_time_us":13890,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28323,"lbm_writes_lt_1ms":443,"mutex_wait_us":521,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8960,"update_count":2000}
I20260812 06:17:09.388968  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d): perf score=10.126437
I20260812 06:17:09.440428  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.051s	user 0.034s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":20685,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":1500}
I20260812 06:17:09.441145  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d): perf score=2.188937
I20260812 06:17:09.453775  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.012s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4596,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:09.454449  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling MajorDeltaCompactionOp(f9a55047c427485bb1ced02738d2d47d): perf score=1.000000
I20260812 06:17:09.602770  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: MajorDeltaCompactionOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.148s	user 0.091s	sys 0.056s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590348,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":486,"lbm_read_time_us":10479,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29385,"lbm_writes_lt_1ms":443,"mutex_wait_us":55,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":2000}
I20260812 06:17:09.603539  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d): perf score=10.126437
I20260812 06:17:09.664763  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.061s	user 0.036s	sys 0.008s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":20861,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:09.665707  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d): perf score=2.188937
I20260812 06:17:09.682034  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.016s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4754,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:09.682650  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling MajorDeltaCompactionOp(f9a55047c427485bb1ced02738d2d47d): perf score=1.000000
I20260812 06:17:09.837356  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: MajorDeltaCompactionOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.155s	user 0.101s	sys 0.053s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590349,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":643,"lbm_read_time_us":9698,"lbm_reads_lt_1ms":472,"lbm_write_time_us":32133,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":24320,"update_count":2000}
I20260812 06:17:09.838305  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d): perf score=10.126437
I20260812 06:17:09.907114  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.068s	user 0.015s	sys 0.048s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":24747,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:17:09.907864  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d): perf score=2.188937
I20260812 06:17:09.921864  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.014s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5653,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:09.922773  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling MajorDeltaCompactionOp(f9a55047c427485bb1ced02738d2d47d): perf score=1.000000
I20260812 06:17:10.117884  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: MajorDeltaCompactionOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.195s	user 0.135s	sys 0.059s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590348,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":338,"lbm_read_time_us":16692,"lbm_reads_lt_1ms":472,"lbm_write_time_us":31371,"lbm_writes_lt_1ms":443,"mutex_wait_us":38,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":39936,"update_count":2000}
I20260812 06:17:10.119146  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d): perf score=11.118625
I20260812 06:17:10.170199  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.050s	user 0.024s	sys 0.024s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":22167,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:10.170987  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d): perf score=2.188937
I20260812 06:17:10.186481  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5493,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:10.187445  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling FlushMRSOp(f9a55047c427485bb1ced02738d2d47d): perf score=1.000000
I20260812 06:17:10.224377  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: FlushMRSOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.037s	user 0.035s	sys 0.000s Metrics: {"bytes_written":1234474,"cfile_init":1,"dirs.queue_time_us":94,"dirs.run_cpu_time_us":437,"dirs.run_wall_time_us":2244,"drs_written":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2002,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:17:10.225318  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling LogGCOp(f9a55047c427485bb1ced02738d2d47d): free 120553389 bytes of WAL
I20260812 06:17:10.225647  1196 log_reader.cc:385] T f9a55047c427485bb1ced02738d2d47d: removed 12 log segments from log reader
I20260812 06:17:10.225699  1196 log.cc:1079] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420410567-840-0/minicluster-data/ts-0-root/wals/f9a55047c427485bb1ced02738d2d47d/wal-000000002 (ops 7-11)
I20260812 06:17:10.225739  1196 log.cc:1079] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420410567-840-0/minicluster-data/ts-0-root/wals/f9a55047c427485bb1ced02738d2d47d/wal-000000003 (ops 12-16)
I20260812 06:17:10.225821  1196 log.cc:1079] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420410567-840-0/minicluster-data/ts-0-root/wals/f9a55047c427485bb1ced02738d2d47d/wal-000000004 (ops 17-21)
I20260812 06:17:10.225903  1196 log.cc:1079] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420410567-840-0/minicluster-data/ts-0-root/wals/f9a55047c427485bb1ced02738d2d47d/wal-000000005 (ops 22-26)
I20260812 06:17:10.225952  1196 log.cc:1079] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420410567-840-0/minicluster-data/ts-0-root/wals/f9a55047c427485bb1ced02738d2d47d/wal-000000006 (ops 27-30)
I20260812 06:17:10.226011  1196 log.cc:1079] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420410567-840-0/minicluster-data/ts-0-root/wals/f9a55047c427485bb1ced02738d2d47d/wal-000000007 (ops 31-35)
I20260812 06:17:10.226058  1196 log.cc:1079] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420410567-840-0/minicluster-data/ts-0-root/wals/f9a55047c427485bb1ced02738d2d47d/wal-000000008 (ops 36-40)
I20260812 06:17:10.226101  1196 log.cc:1079] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420410567-840-0/minicluster-data/ts-0-root/wals/f9a55047c427485bb1ced02738d2d47d/wal-000000009 (ops 41-44)
I20260812 06:17:10.226140  1196 log.cc:1079] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420410567-840-0/minicluster-data/ts-0-root/wals/f9a55047c427485bb1ced02738d2d47d/wal-000000010 (ops 45-49)
I20260812 06:17:10.226188  1196 log.cc:1079] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420410567-840-0/minicluster-data/ts-0-root/wals/f9a55047c427485bb1ced02738d2d47d/wal-000000011 (ops 50-54)
I20260812 06:17:10.226231  1196 log.cc:1079] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420410567-840-0/minicluster-data/ts-0-root/wals/f9a55047c427485bb1ced02738d2d47d/wal-000000012 (ops 55-59)
I20260812 06:17:10.226275  1196 log.cc:1079] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420410567-840-0/minicluster-data/ts-0-root/wals/f9a55047c427485bb1ced02738d2d47d/wal-000000013 (ops 60-64)
I20260812 06:17:10.257933  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: LogGCOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.032s	user 0.000s	sys 0.031s Metrics: {}
I20260812 06:17:10.258582  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling UndoDeltaBlockGCOp(f9a55047c427485bb1ced02738d2d47d): 473 bytes on disk
I20260812 06:17:10.259215  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: UndoDeltaBlockGCOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":95,"lbm_reads_lt_1ms":4}
I20260812 06:17:10.259804  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d): perf score=3.181125
I20260812 06:17:10.285320  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.025s	user 0.018s	sys 0.007s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":5102,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:10.286085  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d): perf score=2.188937
I20260812 06:17:10.299549  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5215,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:10.300155  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling MajorDeltaCompactionOp(f9a55047c427485bb1ced02738d2d47d): perf score=1.000000
I20260812 06:17:10.535832  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: MajorDeltaCompactionOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.235s	user 0.143s	sys 0.092s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28795390,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":366,"lbm_read_time_us":17334,"lbm_reads_lt_1ms":674,"lbm_write_time_us":40142,"lbm_writes_lt_1ms":643,"mutex_wait_us":134,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1280,"thread_start_us":93,"threads_started":1,"update_count":3000}
I20260812 06:17:10.537079  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d): perf score=14.095187
I20260812 06:17:10.605955  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.069s	user 0.038s	sys 0.027s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23630,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:10.606724  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d): perf score=2.188937
I20260812 06:17:10.619863  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.013s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5121,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:10.620486  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling MajorDeltaCompactionOp(f9a55047c427485bb1ced02738d2d47d): perf score=1.000000
I20260812 06:17:10.825846  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: MajorDeltaCompactionOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.205s	user 0.131s	sys 0.072s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692759,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1149,"lbm_read_time_us":16123,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32764,"lbm_writes_lt_1ms":543,"mutex_wait_us":1,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5888,"update_count":2500}
I20260812 06:17:10.826922  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d): perf score=11.118625
I20260812 06:17:10.887254  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.060s	user 0.029s	sys 0.023s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":27295,"lbm_writes_1-10_ms":4,"lbm_writes_lt_1ms":309,"reinsert_count":0,"update_count":1550}
I20260812 06:17:10.887825  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d): perf score=2.188937
I20260812 06:17:10.916378  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.028s	user 0.013s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4659,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:10.917173  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d): perf score=2.188937
I20260812 06:17:10.933379  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.016s	user 0.015s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6003,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:10.933997  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling MajorDeltaCompactionOp(f9a55047c427485bb1ced02738d2d47d): perf score=1.000000
I20260812 06:17:11.149663  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: MajorDeltaCompactionOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.215s	user 0.147s	sys 0.063s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24692870,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":665,"lbm_read_time_us":16623,"lbm_reads_lt_1ms":573,"lbm_write_time_us":32630,"lbm_writes_lt_1ms":543,"mutex_wait_us":83,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2500}
I20260812 06:17:11.150395  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d): perf score=11.118625
I20260812 06:17:11.188261  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.038s	user 0.023s	sys 0.011s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16266,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:11.189141  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d): perf score=2.188937
I20260812 06:17:11.210165  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.021s	user 0.015s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6403,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:11.210865  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling MajorDeltaCompactionOp(f9a55047c427485bb1ced02738d2d47d): perf score=1.000000
I20260812 06:17:11.369246  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: MajorDeltaCompactionOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.158s	user 0.117s	sys 0.039s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590338,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":831,"lbm_read_time_us":10651,"lbm_reads_lt_1ms":464,"lbm_write_time_us":29074,"lbm_writes_lt_1ms":443,"mutex_wait_us":71,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2000}
I20260812 06:17:11.370488  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d): perf score=10.126437
I20260812 06:17:11.415841  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.045s	user 0.019s	sys 0.017s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":17456,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:11.416745  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d): perf score=2.188937
I20260812 06:17:11.435801  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.019s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7309,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:11.436565  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling MajorDeltaCompactionOp(f9a55047c427485bb1ced02738d2d47d): perf score=1.000000
I20260812 06:17:11.593240  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: MajorDeltaCompactionOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.156s	user 0.117s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590346,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1244,"lbm_read_time_us":12025,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26295,"lbm_writes_lt_1ms":443,"mutex_wait_us":150,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2000}
I20260812 06:17:11.594254  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d): perf score=10.126437
I20260812 06:17:11.636940  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.042s	user 0.028s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17232,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:11.637588  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling MajorDeltaCompactionOp(f9a55047c427485bb1ced02738d2d47d): perf score=1.000000
I20260812 06:17:11.758832  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: MajorDeltaCompactionOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.121s	user 0.103s	sys 0.016s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16487816,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":2837,"lbm_read_time_us":7001,"lbm_reads_lt_1ms":363,"lbm_write_time_us":23887,"lbm_writes_lt_1ms":343,"mutex_wait_us":721,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":145280,"update_count":1500}
I20260812 06:17:11.759526  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d): perf score=10.126437
I20260812 06:17:11.813225  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.053s	user 0.034s	sys 0.019s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":25900,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":300,"reinsert_count":0,"update_count":1500}
I20260812 06:17:11.813899  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d): perf score=2.188937
I20260812 06:17:11.831060  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.017s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6100,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:11.831678  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling MajorDeltaCompactionOp(f9a55047c427485bb1ced02738d2d47d): perf score=1.000000
I20260812 06:17:12.000465  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: MajorDeltaCompactionOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.169s	user 0.138s	sys 0.027s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590350,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":275,"lbm_read_time_us":11213,"lbm_reads_lt_1ms":472,"lbm_write_time_us":33539,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":32128,"update_count":2000}
I20260812 06:17:12.001108  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d): perf score=10.126437
I20260812 06:17:12.053926  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.053s	user 0.036s	sys 0.013s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":24143,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:17:12.054612  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d): perf score=2.188937
I20260812 06:17:12.067099  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4505,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:12.068287  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling FlushMRSOp(f9a55047c427485bb1ced02738d2d47d): perf score=1.000000
I20260812 06:17:12.103878  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: FlushMRSOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.035s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":107,"dirs.run_cpu_time_us":406,"dirs.run_wall_time_us":1784,"drs_written":1,"lbm_read_time_us":84,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2360,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:12.104782  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling LogGCOp(f9a55047c427485bb1ced02738d2d47d): free 129320498 bytes of WAL
I20260812 06:17:12.105139  1196 log_reader.cc:385] T f9a55047c427485bb1ced02738d2d47d: removed 13 log segments from log reader
I20260812 06:17:12.105223  1196 log.cc:1079] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420410567-840-0/minicluster-data/ts-0-root/wals/f9a55047c427485bb1ced02738d2d47d/wal-000000014 (ops 65-69)
I20260812 06:17:12.105284  1196 log.cc:1079] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420410567-840-0/minicluster-data/ts-0-root/wals/f9a55047c427485bb1ced02738d2d47d/wal-000000015 (ops 70-74)
I20260812 06:17:12.105322  1196 log.cc:1079] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420410567-840-0/minicluster-data/ts-0-root/wals/f9a55047c427485bb1ced02738d2d47d/wal-000000016 (ops 75-79)
I20260812 06:17:12.105366  1196 log.cc:1079] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420410567-840-0/minicluster-data/ts-0-root/wals/f9a55047c427485bb1ced02738d2d47d/wal-000000017 (ops 80-84)
I20260812 06:17:12.105399  1196 log.cc:1079] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420410567-840-0/minicluster-data/ts-0-root/wals/f9a55047c427485bb1ced02738d2d47d/wal-000000018 (ops 85-88)
I20260812 06:17:12.105432  1196 log.cc:1079] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420410567-840-0/minicluster-data/ts-0-root/wals/f9a55047c427485bb1ced02738d2d47d/wal-000000019 (ops 89-93)
I20260812 06:17:12.105472  1196 log.cc:1079] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420410567-840-0/minicluster-data/ts-0-root/wals/f9a55047c427485bb1ced02738d2d47d/wal-000000020 (ops 94-98)
I20260812 06:17:12.105510  1196 log.cc:1079] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420410567-840-0/minicluster-data/ts-0-root/wals/f9a55047c427485bb1ced02738d2d47d/wal-000000021 (ops 99-103)
I20260812 06:17:12.105549  1196 log.cc:1079] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420410567-840-0/minicluster-data/ts-0-root/wals/f9a55047c427485bb1ced02738d2d47d/wal-000000022 (ops 104-108)
I20260812 06:17:12.105587  1196 log.cc:1079] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420410567-840-0/minicluster-data/ts-0-root/wals/f9a55047c427485bb1ced02738d2d47d/wal-000000023 (ops 109-113)
I20260812 06:17:12.105624  1196 log.cc:1079] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420410567-840-0/minicluster-data/ts-0-root/wals/f9a55047c427485bb1ced02738d2d47d/wal-000000024 (ops 114-118)
I20260812 06:17:12.105662  1196 log.cc:1079] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420410567-840-0/minicluster-data/ts-0-root/wals/f9a55047c427485bb1ced02738d2d47d/wal-000000025 (ops 119-122)
I20260812 06:17:12.105702  1196 log.cc:1079] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420410567-840-0/minicluster-data/ts-0-root/wals/f9a55047c427485bb1ced02738d2d47d/wal-000000026 (ops 123-127)
I20260812 06:17:12.138068  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: LogGCOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.033s	user 0.000s	sys 0.032s Metrics: {}
I20260812 06:17:12.138629  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling UndoDeltaBlockGCOp(f9a55047c427485bb1ced02738d2d47d): 482 bytes on disk
I20260812 06:17:12.139258  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: UndoDeltaBlockGCOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":78,"lbm_reads_lt_1ms":4}
I20260812 06:17:12.140261  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d): perf score=2.188937
I20260812 06:17:12.155184  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4266758,"delete_count":0,"lbm_write_time_us":5326,"lbm_writes_lt_1ms":107,"reinsert_count":0,"update_count":520}
I20260812 06:17:12.155830  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d): perf score=2.188937
I20260812 06:17:12.166989  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3938559,"delete_count":0,"lbm_write_time_us":4135,"lbm_writes_lt_1ms":99,"reinsert_count":0,"update_count":480}
I20260812 06:17:12.167622  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling MajorDeltaCompactionOp(f9a55047c427485bb1ced02738d2d47d): perf score=1.000000
I20260812 06:17:12.359946  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: MajorDeltaCompactionOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.192s	user 0.135s	sys 0.051s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28795407,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":511,"lbm_read_time_us":13454,"lbm_reads_lt_1ms":674,"lbm_write_time_us":39269,"lbm_writes_lt_1ms":643,"mutex_wait_us":58,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3456,"thread_start_us":93,"threads_started":1,"update_count":3000}
I20260812 06:17:12.360857  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d): perf score=14.095187
I20260812 06:17:12.455272  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.094s	user 0.030s	sys 0.019s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":65995,"lbm_writes_1-10_ms":1,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:12.456087  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d): perf score=2.188937
I20260812 06:17:12.488541  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.032s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5829,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:12.489902  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d): perf score=2.188937
I20260812 06:17:12.505008  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.015s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5267,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:12.505642  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling MajorDeltaCompactionOp(f9a55047c427485bb1ced02738d2d47d): perf score=1.000000
I20260812 06:17:12.750487  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: MajorDeltaCompactionOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.245s	user 0.187s	sys 0.051s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28795290,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":450,"lbm_read_time_us":15804,"lbm_reads_lt_1ms":673,"lbm_write_time_us":40049,"lbm_writes_lt_1ms":643,"mutex_wait_us":340,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":3000}
I20260812 06:17:12.751667  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d): perf score=14.095187
I20260812 06:17:12.810326  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.058s	user 0.037s	sys 0.020s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":26167,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:12.811107  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d): perf score=2.188937
I20260812 06:17:12.844110  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.033s	user 0.017s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7152,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:12.845009  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d): perf score=1.000000
I20260812 06:17:12.856667  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.011s	user 0.005s	sys 0.000s Metrics: {"bytes_written":1312956,"delete_count":0,"lbm_write_time_us":1879,"lbm_writes_lt_1ms":35,"reinsert_count":0,"update_count":160}
I20260812 06:17:12.857738  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d): perf score=1.196750
I20260812 06:17:12.872611  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.015s	user 0.009s	sys 0.003s Metrics: {"bytes_written":2789855,"delete_count":0,"lbm_write_time_us":5329,"lbm_writes_lt_1ms":71,"reinsert_count":0,"update_count":340}
I20260812 06:17:12.873440  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling MajorDeltaCompactionOp(f9a55047c427485bb1ced02738d2d47d): perf score=1.000000
I20260812 06:17:13.087081  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: MajorDeltaCompactionOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.213s	user 0.125s	sys 0.085s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28795316,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":207,"lbm_read_time_us":16459,"lbm_reads_lt_1ms":674,"lbm_write_time_us":37272,"lbm_writes_lt_1ms":643,"mutex_wait_us":80,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":3000}
I20260812 06:17:13.087905  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d): perf score=14.095187
I20260812 06:17:13.154266  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.066s	user 0.026s	sys 0.031s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20642,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:13.154874  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d): perf score=2.188937
I20260812 06:17:13.168592  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5230,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:13.169454  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling MajorDeltaCompactionOp(f9a55047c427485bb1ced02738d2d47d): perf score=1.000000
I20260812 06:17:13.374336  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: MajorDeltaCompactionOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.205s	user 0.148s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692757,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":2058,"lbm_read_time_us":15186,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32352,"lbm_writes_lt_1ms":543,"mutex_wait_us":695,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":58368,"update_count":2500}
I20260812 06:17:13.375257  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d): perf score=14.095187
I20260812 06:17:13.451198  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.076s	user 0.035s	sys 0.035s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":26702,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:13.452152  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d): perf score=2.188937
I20260812 06:17:13.467507  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5236,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:13.468353  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling MajorDeltaCompactionOp(f9a55047c427485bb1ced02738d2d47d): perf score=1.000000
I20260812 06:17:13.687599  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: MajorDeltaCompactionOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.219s	user 0.150s	sys 0.059s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692759,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":705,"lbm_read_time_us":16672,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34627,"lbm_writes_lt_1ms":543,"mutex_wait_us":59,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16512,"update_count":2500}
I20260812 06:17:13.688459  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d): perf score=14.095187
I20260812 06:17:13.753430  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.065s	user 0.032s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24940,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:13.754122  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d): perf score=2.188937
I20260812 06:17:13.766320  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.012s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4344,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:13.767232  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling FlushMRSOp(f9a55047c427485bb1ced02738d2d47d): perf score=1.000000
I20260812 06:17:13.811837  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: FlushMRSOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.044s	user 0.040s	sys 0.000s Metrics: {"bytes_written":1193505,"cfile_init":1,"dirs.queue_time_us":118,"dirs.run_cpu_time_us":238,"dirs.run_wall_time_us":1551,"drs_written":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1819,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:13.812873  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling LogGCOp(f9a55047c427485bb1ced02738d2d47d): free 120553648 bytes of WAL
I20260812 06:17:13.813215  1196 log_reader.cc:385] T f9a55047c427485bb1ced02738d2d47d: removed 12 log segments from log reader
I20260812 06:17:13.813289  1196 log.cc:1079] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420410567-840-0/minicluster-data/ts-0-root/wals/f9a55047c427485bb1ced02738d2d47d/wal-000000027 (ops 128-132)
I20260812 06:17:13.813334  1196 log.cc:1079] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420410567-840-0/minicluster-data/ts-0-root/wals/f9a55047c427485bb1ced02738d2d47d/wal-000000028 (ops 133-137)
I20260812 06:17:13.813361  1196 log.cc:1079] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420410567-840-0/minicluster-data/ts-0-root/wals/f9a55047c427485bb1ced02738d2d47d/wal-000000029 (ops 138-142)
I20260812 06:17:13.813390  1196 log.cc:1079] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420410567-840-0/minicluster-data/ts-0-root/wals/f9a55047c427485bb1ced02738d2d47d/wal-000000030 (ops 143-146)
I20260812 06:17:13.813421  1196 log.cc:1079] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420410567-840-0/minicluster-data/ts-0-root/wals/f9a55047c427485bb1ced02738d2d47d/wal-000000031 (ops 147-151)
I20260812 06:17:13.813447  1196 log.cc:1079] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420410567-840-0/minicluster-data/ts-0-root/wals/f9a55047c427485bb1ced02738d2d47d/wal-000000032 (ops 152-156)
I20260812 06:17:13.813481  1196 log.cc:1079] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420410567-840-0/minicluster-data/ts-0-root/wals/f9a55047c427485bb1ced02738d2d47d/wal-000000033 (ops 157-160)
I20260812 06:17:13.813516  1196 log.cc:1079] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420410567-840-0/minicluster-data/ts-0-root/wals/f9a55047c427485bb1ced02738d2d47d/wal-000000034 (ops 161-165)
I20260812 06:17:13.813542  1196 log.cc:1079] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420410567-840-0/minicluster-data/ts-0-root/wals/f9a55047c427485bb1ced02738d2d47d/wal-000000035 (ops 166-170)
I20260812 06:17:13.813568  1196 log.cc:1079] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420410567-840-0/minicluster-data/ts-0-root/wals/f9a55047c427485bb1ced02738d2d47d/wal-000000036 (ops 171-175)
I20260812 06:17:13.813606  1196 log.cc:1079] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420410567-840-0/minicluster-data/ts-0-root/wals/f9a55047c427485bb1ced02738d2d47d/wal-000000037 (ops 176-180)
I20260812 06:17:13.813642  1196 log.cc:1079] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5: Deleting log segment in path: /tmp/dist-test-taskyVvZZi/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515420410567-840-0/minicluster-data/ts-0-root/wals/f9a55047c427485bb1ced02738d2d47d/wal-000000038 (ops 181-185)
I20260812 06:17:13.849525  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: LogGCOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.036s	user 0.001s	sys 0.035s Metrics: {}
I20260812 06:17:13.850176  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling UndoDeltaBlockGCOp(f9a55047c427485bb1ced02738d2d47d): 463 bytes on disk
I20260812 06:17:13.850795  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: UndoDeltaBlockGCOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4}
I20260812 06:17:13.851464  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d): perf score=2.188937
I20260812 06:17:13.866847  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.015s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5455,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:13.867575  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling MajorDeltaCompactionOp(f9a55047c427485bb1ced02738d2d47d): perf score=1.000000
I20260812 06:17:14.119486  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: MajorDeltaCompactionOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.252s	user 0.179s	sys 0.071s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28795288,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1973,"lbm_read_time_us":18549,"lbm_reads_lt_1ms":665,"lbm_write_time_us":43873,"lbm_writes_lt_1ms":643,"mutex_wait_us":1322,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2816,"thread_start_us":93,"threads_started":1,"update_count":3000}
I20260812 06:17:14.120385  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d): perf score=18.063937
I20260812 06:17:14.197818  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.077s	user 0.052s	sys 0.024s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":34476,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:17:14.198935  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d): perf score=2.188937
I20260812 06:17:14.218684  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: FlushDeltaMemStoresOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.020s	user 0.000s	sys 0.014s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6607,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":500}
I20260812 06:17:14.219293  1266 maintenance_manager.cc:419] P 5e7e53e1ec7f4611a13539ccef65b3b5: Scheduling MajorDeltaCompactionOp(f9a55047c427485bb1ced02738d2d47d): perf score=1.000000
I20260812 06:17:14.237160   840 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.991s	user 2.166s	sys 0.205s
I20260812 06:17:14.345435   840 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.108s	user 0.000s	sys 0.002s
I20260812 06:17:14.346087   840 tablet_server.cc:179] TabletServer@127.0.210.1:0 shutting down...
I20260812 06:17:14.416041  1196 maintenance_manager.cc:643] P 5e7e53e1ec7f4611a13539ccef65b3b5: MajorDeltaCompactionOp(f9a55047c427485bb1ced02738d2d47d) complete. Timing: real 0.197s	user 0.112s	sys 0.084s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28795172,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":883,"lbm_read_time_us":16583,"lbm_reads_lt_1ms":664,"lbm_write_time_us":32683,"lbm_writes_lt_1ms":643,"mutex_wait_us":349,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":62336,"update_count":3000}
I20260812 06:17:14.417084   840 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:14.417477   840 tablet_replica.cc:333] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5: stopping tablet replica
I20260812 06:17:14.417697   840 raft_consensus.cc:2243] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:14.417963   840 raft_consensus.cc:2272] T f9a55047c427485bb1ced02738d2d47d P 5e7e53e1ec7f4611a13539ccef65b3b5 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:14.434515   840 tablet_server.cc:196] TabletServer@127.0.210.1:0 shutdown complete.
I20260812 06:17:14.474064   840 master.cc:562] Master@127.0.210.62:43367 shutting down...
I20260812 06:17:14.480355   840 raft_consensus.cc:2243] T 00000000000000000000000000000000 P de231d8361ae48239f6e649baceb2b1b [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:14.480649   840 raft_consensus.cc:2272] T 00000000000000000000000000000000 P de231d8361ae48239f6e649baceb2b1b [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:14.480928   840 tablet_replica.cc:333] T 00000000000000000000000000000000 P de231d8361ae48239f6e649baceb2b1b: stopping tablet replica
I20260812 06:17:14.494921   840 master.cc:584] Master@127.0.210.62:43367 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (6617 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (14180 ms total)

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