[==========] 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:24.574987 12081 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.11.204.126:45153
I20260812 06:17:24.576574 12081 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:24.577286 12081 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:24.586877 12089 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:24.586869 12091 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:24.587204 12081 server_base.cc:1061] running on GCE node
W20260812 06:17:24.587262 12088 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:24.588049 12081 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:24.588238 12081 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:24.588274 12081 hybrid_clock.cc:648] HybridClock initialized: now 1786515444588272 us; error 0 us; skew 500 ppm
I20260812 06:17:24.591606 12081 webserver.cc:533] Webserver started at http://127.11.204.126:41923/ using document root <none> and password file <none>
I20260812 06:17:24.592670 12081 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:24.592800 12081 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:24.593086 12081 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:24.595546 12081 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444559538-12081-0/minicluster-data/master-0-root/instance:
uuid: "244a255b940e4596982a65d22f2d5920"
format_stamp: "Formatted at 2026-08-12 06:17:24 on dist-test-slave-dhph"
I20260812 06:17:24.603658 12081 fs_manager.cc:696] Time spent creating directory manager: real 0.007s	user 0.007s	sys 0.000s
I20260812 06:17:24.608171 12097 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:24.610504 12081 fs_manager.cc:730] Time spent opening block manager: real 0.004s	user 0.002s	sys 0.003s
I20260812 06:17:24.610728 12081 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444559538-12081-0/minicluster-data/master-0-root
uuid: "244a255b940e4596982a65d22f2d5920"
format_stamp: "Formatted at 2026-08-12 06:17:24 on dist-test-slave-dhph"
I20260812 06:17:24.610854 12081 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444559538-12081-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444559538-12081-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444559538-12081-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:24.638084 12081 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:24.639524 12081 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:24.639734 12081 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:24.650097 12156 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.11.204.126:45153 every 8 connection(s)
I20260812 06:17:24.650098 12081 rpc_server.cc:307] RPC server started. Bound to: 127.11.204.126:45153
I20260812 06:17:24.653195 12157 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:24.660940 12157 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 244a255b940e4596982a65d22f2d5920: Bootstrap starting.
I20260812 06:17:24.664279 12157 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 244a255b940e4596982a65d22f2d5920: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:24.665462 12157 log.cc:826] T 00000000000000000000000000000000 P 244a255b940e4596982a65d22f2d5920: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:24.668463 12157 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 244a255b940e4596982a65d22f2d5920: No bootstrap required, opened a new log
I20260812 06:17:24.672124 12157 raft_consensus.cc:359] T 00000000000000000000000000000000 P 244a255b940e4596982a65d22f2d5920 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "244a255b940e4596982a65d22f2d5920" member_type: VOTER }
I20260812 06:17:24.672403 12157 raft_consensus.cc:385] T 00000000000000000000000000000000 P 244a255b940e4596982a65d22f2d5920 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:24.672546 12157 raft_consensus.cc:740] T 00000000000000000000000000000000 P 244a255b940e4596982a65d22f2d5920 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 244a255b940e4596982a65d22f2d5920, State: Initialized, Role: FOLLOWER
I20260812 06:17:24.673362 12157 consensus_queue.cc:260] T 00000000000000000000000000000000 P 244a255b940e4596982a65d22f2d5920 [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: "244a255b940e4596982a65d22f2d5920" member_type: VOTER }
I20260812 06:17:24.673589 12157 raft_consensus.cc:399] T 00000000000000000000000000000000 P 244a255b940e4596982a65d22f2d5920 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:24.673681 12157 raft_consensus.cc:493] T 00000000000000000000000000000000 P 244a255b940e4596982a65d22f2d5920 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:24.673856 12157 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 244a255b940e4596982a65d22f2d5920 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:24.731326 12157 raft_consensus.cc:515] T 00000000000000000000000000000000 P 244a255b940e4596982a65d22f2d5920 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "244a255b940e4596982a65d22f2d5920" member_type: VOTER }
I20260812 06:17:24.732120 12157 leader_election.cc:304] T 00000000000000000000000000000000 P 244a255b940e4596982a65d22f2d5920 [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: 244a255b940e4596982a65d22f2d5920; no voters: 
I20260812 06:17:24.732605 12157 leader_election.cc:290] T 00000000000000000000000000000000 P 244a255b940e4596982a65d22f2d5920 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:24.732821 12160 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 244a255b940e4596982a65d22f2d5920 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:24.733112 12160 raft_consensus.cc:697] T 00000000000000000000000000000000 P 244a255b940e4596982a65d22f2d5920 [term 1 LEADER]: Becoming Leader. State: Replica: 244a255b940e4596982a65d22f2d5920, State: Running, Role: LEADER
I20260812 06:17:24.733714 12160 consensus_queue.cc:237] T 00000000000000000000000000000000 P 244a255b940e4596982a65d22f2d5920 [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: "244a255b940e4596982a65d22f2d5920" member_type: VOTER }
I20260812 06:17:24.733939 12157 sys_catalog.cc:565] T 00000000000000000000000000000000 P 244a255b940e4596982a65d22f2d5920 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:24.736243 12162 sys_catalog.cc:455] T 00000000000000000000000000000000 P 244a255b940e4596982a65d22f2d5920 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 244a255b940e4596982a65d22f2d5920. Latest consensus state: current_term: 1 leader_uuid: "244a255b940e4596982a65d22f2d5920" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "244a255b940e4596982a65d22f2d5920" member_type: VOTER } }
I20260812 06:17:24.736413 12162 sys_catalog.cc:458] T 00000000000000000000000000000000 P 244a255b940e4596982a65d22f2d5920 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:24.736778 12161 sys_catalog.cc:455] T 00000000000000000000000000000000 P 244a255b940e4596982a65d22f2d5920 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "244a255b940e4596982a65d22f2d5920" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "244a255b940e4596982a65d22f2d5920" member_type: VOTER } }
I20260812 06:17:24.736868 12161 sys_catalog.cc:458] T 00000000000000000000000000000000 P 244a255b940e4596982a65d22f2d5920 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:24.737210 12175 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:24.737444 12081 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:24.739847 12175 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:24.747243 12175 catalog_manager.cc:1383] Generated new cluster ID: f96b968a6bd243a69a0afd7a673c02e5
I20260812 06:17:24.747357 12175 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:24.767912 12175 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:24.769028 12175 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:24.778714 12175 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 244a255b940e4596982a65d22f2d5920: Generated new TSK 0
I20260812 06:17:24.780009 12175 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:24.803243 12081 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:24.806818 12187 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:24.806849 12188 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:24.806958 12190 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:24.807184 12081 server_base.cc:1061] running on GCE node
I20260812 06:17:24.807395 12081 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:24.807451 12081 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:24.807475 12081 hybrid_clock.cc:648] HybridClock initialized: now 1786515444807475 us; error 0 us; skew 500 ppm
I20260812 06:17:24.808934 12081 webserver.cc:533] Webserver started at http://127.11.204.65:40577/ using document root <none> and password file <none>
I20260812 06:17:24.809311 12081 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:24.809389 12081 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:24.809471 12081 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:24.810108 12081 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444559538-12081-0/minicluster-data/ts-0-root/instance:
uuid: "24941c49c2db48cfa47971b3e8e97cda"
format_stamp: "Formatted at 2026-08-12 06:17:24 on dist-test-slave-dhph"
I20260812 06:17:24.813045 12081 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:17:24.814759 12195 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:24.815172 12081 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:24.815387 12081 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444559538-12081-0/minicluster-data/ts-0-root
uuid: "24941c49c2db48cfa47971b3e8e97cda"
format_stamp: "Formatted at 2026-08-12 06:17:24 on dist-test-slave-dhph"
I20260812 06:17:24.815481 12081 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444559538-12081-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444559538-12081-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444559538-12081-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:24.826143 12081 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:24.827101 12081 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:24.827888 12081 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:24.830188 12081 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:24.830292 12081 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:24.830363 12081 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:24.830467 12081 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.001s	sys 0.000s
I20260812 06:17:24.841799 12081 rpc_server.cc:307] RPC server started. Bound to: 127.11.204.65:46217
I20260812 06:17:24.841830 12269 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.11.204.65:46217 every 8 connection(s)
I20260812 06:17:24.863698 12270 heartbeater.cc:344] Connected to a master server at 127.11.204.126:45153
I20260812 06:17:24.864109 12270 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:24.864670 12270 heartbeater.cc:507] Master 127.11.204.126:45153 requested a full tablet report, sending...
I20260812 06:17:24.866741 12116 ts_manager.cc:194] Registered new tserver with Master: 24941c49c2db48cfa47971b3e8e97cda (127.11.204.65:46217)
I20260812 06:17:24.867161 12081 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.023406614s
I20260812 06:17:24.868723 12116 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:45794
I20260812 06:17:24.880359 12116 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:45802:
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:24.903474 12228 tablet_service.cc:1511] Processing CreateTablet for tablet f7a858bb2fc740fc91314acc933a53ad (DEFAULT_TABLE table=heavy-update-compaction-test [id=18fbbf2f84a54226a3d7c257fcab27ae]), partition=
I20260812 06:17:24.904072 12228 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet f7a858bb2fc740fc91314acc933a53ad. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:24.907032 12284 tablet_bootstrap.cc:492] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda: Bootstrap starting.
I20260812 06:17:24.908584 12284 tablet_bootstrap.cc:654] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:24.910907 12284 tablet_bootstrap.cc:492] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda: No bootstrap required, opened a new log
I20260812 06:17:24.911082 12284 ts_tablet_manager.cc:1403] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda: Time spent bootstrapping tablet: real 0.004s	user 0.002s	sys 0.001s
I20260812 06:17:24.911620 12284 raft_consensus.cc:359] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "24941c49c2db48cfa47971b3e8e97cda" member_type: VOTER last_known_addr { host: "127.11.204.65" port: 46217 } }
I20260812 06:17:24.911787 12284 raft_consensus.cc:385] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:24.911844 12284 raft_consensus.cc:740] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 24941c49c2db48cfa47971b3e8e97cda, State: Initialized, Role: FOLLOWER
I20260812 06:17:24.912019 12284 consensus_queue.cc:260] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda [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: "24941c49c2db48cfa47971b3e8e97cda" member_type: VOTER last_known_addr { host: "127.11.204.65" port: 46217 } }
I20260812 06:17:24.912130 12284 raft_consensus.cc:399] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:24.912189 12284 raft_consensus.cc:493] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:24.912251 12284 raft_consensus.cc:3060] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:24.928027 12284 raft_consensus.cc:515] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "24941c49c2db48cfa47971b3e8e97cda" member_type: VOTER last_known_addr { host: "127.11.204.65" port: 46217 } }
I20260812 06:17:24.928424 12284 leader_election.cc:304] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda [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: 24941c49c2db48cfa47971b3e8e97cda; no voters: 
I20260812 06:17:24.928821 12284 leader_election.cc:290] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:24.929648 12287 raft_consensus.cc:2804] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:24.930110 12287 raft_consensus.cc:697] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda [term 1 LEADER]: Becoming Leader. State: Replica: 24941c49c2db48cfa47971b3e8e97cda, State: Running, Role: LEADER
I20260812 06:17:24.930683 12270 heartbeater.cc:499] Master 127.11.204.126:45153 was elected leader, sending a full tablet report...
I20260812 06:17:24.929728 12284 ts_tablet_manager.cc:1434] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda: Time spent starting tablet: real 0.019s	user 0.000s	sys 0.004s
I20260812 06:17:24.931072 12287 consensus_queue.cc:237] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda [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: "24941c49c2db48cfa47971b3e8e97cda" member_type: VOTER last_known_addr { host: "127.11.204.65" port: 46217 } }
I20260812 06:17:24.935986 12116 catalog_manager.cc:5719] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda reported cstate change: term changed from 0 to 1, leader changed from <none> to 24941c49c2db48cfa47971b3e8e97cda (127.11.204.65). New cstate: current_term: 1 leader_uuid: "24941c49c2db48cfa47971b3e8e97cda" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "24941c49c2db48cfa47971b3e8e97cda" member_type: VOTER last_known_addr { host: "127.11.204.65" port: 46217 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:25.035642 12081 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.089s	user 0.034s	sys 0.005s
I20260812 06:17:25.094822 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling FlushMRSOp(f7a858bb2fc740fc91314acc933a53ad): perf score=6.156503
I20260812 06:17:25.223335 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: FlushMRSOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.128s	user 0.113s	sys 0.013s Metrics: {"bytes_written":4677002,"cfile_init":1,"compiler_manager_pool.queue_time_us":78,"delete_count":0,"dirs.queue_time_us":164,"dirs.run_cpu_time_us":347,"dirs.run_wall_time_us":1175,"drs_written":1,"lbm_read_time_us":103,"lbm_reads_lt_1ms":4,"lbm_write_time_us":21690,"lbm_writes_lt_1ms":271,"peak_mem_usage":0,"reinsert_count":0,"rows_written":101,"spinlock_wait_cycles":348288,"update_count":570}
I20260812 06:17:25.224555 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling LogGCOp(f7a858bb2fc740fc91314acc933a53ad): free 11976772 bytes of WAL
I20260812 06:17:25.224891 12201 log_reader.cc:385] T f7a858bb2fc740fc91314acc933a53ad: removed 1 log segments from log reader
I20260812 06:17:25.224972 12201 log.cc:1079] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/f7a858bb2fc740fc91314acc933a53ad/wal-000000001 (ops 1-6)
I20260812 06:17:25.227916 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: LogGCOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.003s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:17:25.228317 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad): perf score=2.188937
I20260812 06:17:25.243844 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.015s	user 0.005s	sys 0.009s Metrics: {"bytes_written":3528305,"delete_count":0,"lbm_write_time_us":5598,"lbm_writes_lt_1ms":89,"reinsert_count":0,"update_count":430}
I20260812 06:17:25.244355 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling MajorDeltaCompactionOp(f7a858bb2fc740fc91314acc933a53ad): perf score=1.000000
I20260812 06:17:25.362629 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: MajorDeltaCompactionOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.118s	user 0.102s	sys 0.012s Metrics: {"cfile_cache_miss":232,"cfile_cache_miss_bytes":12344546,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":481,"lbm_read_time_us":6020,"lbm_reads_lt_1ms":264,"lbm_write_time_us":16906,"lbm_writes_lt_1ms":243,"peak_mem_usage":25836184,"reinsert_count":0,"thread_start_us":360,"threads_started":5,"update_count":1000}
I20260812 06:17:25.363773 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad): perf score=6.157687
I20260812 06:17:25.409116 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.045s	user 0.029s	sys 0.008s Metrics: {"bytes_written":8205080,"delete_count":0,"lbm_write_time_us":17198,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":202,"reinsert_count":0,"update_count":1000}
I20260812 06:17:25.409659 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling MajorDeltaCompactionOp(f7a858bb2fc740fc91314acc933a53ad): perf score=1.000000
I20260812 06:17:25.534417 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: MajorDeltaCompactionOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.124s	user 0.090s	sys 0.021s Metrics: {"cfile_cache_miss":231,"cfile_cache_miss_bytes":12344441,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":626,"lbm_read_time_us":6120,"lbm_reads_lt_1ms":263,"lbm_write_time_us":19470,"lbm_writes_lt_1ms":243,"mutex_wait_us":28,"peak_mem_usage":25836184,"reinsert_count":0,"spinlock_wait_cycles":87808,"update_count":1000}
I20260812 06:17:25.535224 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling UndoDeltaBlockGCOp(f7a858bb2fc740fc91314acc933a53ad): 4103815 bytes on disk
I20260812 06:17:25.535907 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: UndoDeltaBlockGCOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":112,"lbm_reads_lt_1ms":4}
I20260812 06:17:25.536761 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad): perf score=10.126437
I20260812 06:17:25.588142 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.051s	user 0.026s	sys 0.015s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":18138,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:25.588958 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad): perf score=2.188937
I20260812 06:17:25.601859 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4332,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:25.602770 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling MajorDeltaCompactionOp(f7a858bb2fc740fc91314acc933a53ad): perf score=1.000000
I20260812 06:17:25.766299 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: MajorDeltaCompactionOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.163s	user 0.114s	sys 0.045s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20549381,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":979,"lbm_read_time_us":8939,"lbm_reads_lt_1ms":472,"lbm_write_time_us":31057,"lbm_writes_lt_1ms":443,"mutex_wait_us":265,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:17:25.767064 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad): perf score=10.126437
I20260812 06:17:25.809502 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.042s	user 0.027s	sys 0.012s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":17530,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:25.810863 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling MajorDeltaCompactionOp(f7a858bb2fc740fc91314acc933a53ad): perf score=1.000000
I20260812 06:17:25.994009 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: MajorDeltaCompactionOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.183s	user 0.128s	sys 0.045s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16446850,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":214,"lbm_read_time_us":9560,"lbm_reads_lt_1ms":363,"lbm_write_time_us":30086,"lbm_writes_lt_1ms":343,"mutex_wait_us":3,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":1500}
I20260812 06:17:25.994824 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad): perf score=10.126437
I20260812 06:17:26.043875 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.049s	user 0.027s	sys 0.021s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":21823,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:26.044484 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad): perf score=2.188937
I20260812 06:17:26.069595 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.025s	user 0.009s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":7593,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:26.070134 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling MajorDeltaCompactionOp(f7a858bb2fc740fc91314acc933a53ad): perf score=1.000000
I20260812 06:17:26.247308 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: MajorDeltaCompactionOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.177s	user 0.149s	sys 0.027s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20549381,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":777,"lbm_read_time_us":8977,"lbm_reads_lt_1ms":464,"lbm_write_time_us":34777,"lbm_writes_lt_1ms":443,"mutex_wait_us":285,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:26.248286 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad): perf score=10.126437
I20260812 06:17:26.295501 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.046s	user 0.038s	sys 0.008s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":19361,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:26.296245 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad): perf score=2.188937
I20260812 06:17:26.314174 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.018s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6487,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:26.314992 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling MajorDeltaCompactionOp(f7a858bb2fc740fc91314acc933a53ad): perf score=1.000000
I20260812 06:17:26.480806 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: MajorDeltaCompactionOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.166s	user 0.125s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20549385,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":2071,"lbm_read_time_us":11373,"lbm_reads_lt_1ms":464,"lbm_write_time_us":31074,"lbm_writes_lt_1ms":443,"mutex_wait_us":2,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4352,"update_count":2000}
I20260812 06:17:26.481570 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad): perf score=10.126437
I20260812 06:17:26.546797 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.065s	user 0.039s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":22509,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:26.548436 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad): perf score=2.188937
I20260812 06:17:26.572000 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.023s	user 0.012s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":8068,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:26.572759 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling MajorDeltaCompactionOp(f7a858bb2fc740fc91314acc933a53ad): perf score=1.000000
I20260812 06:17:26.797906 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: MajorDeltaCompactionOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.225s	user 0.158s	sys 0.064s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20549382,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":920,"lbm_read_time_us":15760,"lbm_reads_1-10_ms":1,"lbm_reads_lt_1ms":471,"lbm_write_time_us":40534,"lbm_writes_lt_1ms":443,"mutex_wait_us":741,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:26.798950 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad): perf score=10.126437
I20260812 06:17:26.858161 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.059s	user 0.044s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":23649,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:26.859126 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad): perf score=2.188937
I20260812 06:17:26.885008 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.025s	user 0.014s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":10329,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:26.886003 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling MajorDeltaCompactionOp(f7a858bb2fc740fc91314acc933a53ad): perf score=1.000000
I20260812 06:17:27.060137 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: MajorDeltaCompactionOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.174s	user 0.148s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20549382,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":630,"lbm_read_time_us":13359,"lbm_reads_1-10_ms":1,"lbm_reads_lt_1ms":471,"lbm_write_time_us":33957,"lbm_writes_lt_1ms":443,"mutex_wait_us":23,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1095552,"update_count":2000}
I20260812 06:17:27.061167 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad): perf score=10.126437
I20260812 06:17:27.127121 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.066s	user 0.031s	sys 0.016s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":20657,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:27.127873 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad): perf score=2.188937
I20260812 06:17:27.145964 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.018s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6858,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:27.147217 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling FlushMRSOp(f7a858bb2fc740fc91314acc933a53ad): perf score=1.000000
I20260812 06:17:27.193871 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: FlushMRSOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.046s	user 0.043s	sys 0.000s Metrics: {"bytes_written":1275444,"cfile_init":1,"dirs.queue_time_us":91,"dirs.run_cpu_time_us":263,"dirs.run_wall_time_us":3110,"drs_written":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2470,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:27.195600 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling LogGCOp(f7a858bb2fc740fc91314acc933a53ad): free 117302574 bytes of WAL
I20260812 06:17:27.195935 12201 log_reader.cc:385] T f7a858bb2fc740fc91314acc933a53ad: removed 12 log segments from log reader
I20260812 06:17:27.196008 12201 log.cc:1079] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/f7a858bb2fc740fc91314acc933a53ad/wal-000000002 (ops 7-11)
I20260812 06:17:27.196065 12201 log.cc:1079] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/f7a858bb2fc740fc91314acc933a53ad/wal-000000003 (ops 12-16)
I20260812 06:17:27.196108 12201 log.cc:1079] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/f7a858bb2fc740fc91314acc933a53ad/wal-000000004 (ops 17-21)
I20260812 06:17:27.196149 12201 log.cc:1079] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/f7a858bb2fc740fc91314acc933a53ad/wal-000000005 (ops 22-26)
I20260812 06:17:27.196192 12201 log.cc:1079] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/f7a858bb2fc740fc91314acc933a53ad/wal-000000006 (ops 27-30)
I20260812 06:17:27.196228 12201 log.cc:1079] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/f7a858bb2fc740fc91314acc933a53ad/wal-000000007 (ops 31-35)
I20260812 06:17:27.196269 12201 log.cc:1079] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/f7a858bb2fc740fc91314acc933a53ad/wal-000000008 (ops 36-40)
I20260812 06:17:27.196308 12201 log.cc:1079] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/f7a858bb2fc740fc91314acc933a53ad/wal-000000009 (ops 41-45)
I20260812 06:17:27.196349 12201 log.cc:1079] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/f7a858bb2fc740fc91314acc933a53ad/wal-000000010 (ops 46-50)
I20260812 06:17:27.196388 12201 log.cc:1079] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/f7a858bb2fc740fc91314acc933a53ad/wal-000000011 (ops 51-54)
I20260812 06:17:27.196427 12201 log.cc:1079] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/f7a858bb2fc740fc91314acc933a53ad/wal-000000012 (ops 55-59)
I20260812 06:17:27.196466 12201 log.cc:1079] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/f7a858bb2fc740fc91314acc933a53ad/wal-000000013 (ops 60-64)
I20260812 06:17:27.231365 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: LogGCOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.035s	user 0.003s	sys 0.032s Metrics: {}
I20260812 06:17:27.231974 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling UndoDeltaBlockGCOp(f7a858bb2fc740fc91314acc933a53ad): 483 bytes on disk
I20260812 06:17:27.232525 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: UndoDeltaBlockGCOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":84,"lbm_reads_lt_1ms":4}
I20260812 06:17:27.233279 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad): perf score=3.181125
I20260812 06:17:27.251335 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.018s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":5519,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:27.252494 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling LogGCOp(f7a858bb2fc740fc91314acc933a53ad): free 11564875 bytes of WAL
I20260812 06:17:27.253319 12201 log_reader.cc:385] T f7a858bb2fc740fc91314acc933a53ad: removed 1 log segments from log reader
I20260812 06:17:27.253424 12201 log.cc:1079] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/f7a858bb2fc740fc91314acc933a53ad/wal-000000014 (ops 65-68)
I20260812 06:17:27.256372 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: LogGCOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.003s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:17:27.257105 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad): perf score=2.188937
I20260812 06:17:27.270099 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.013s	user 0.003s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4421,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:27.270848 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling MajorDeltaCompactionOp(f7a858bb2fc740fc91314acc933a53ad): perf score=1.000000
I20260812 06:17:27.492092 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: MajorDeltaCompactionOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.221s	user 0.160s	sys 0.059s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28754432,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":587,"lbm_read_time_us":14679,"lbm_reads_lt_1ms":674,"lbm_write_time_us":45001,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":641,"mutex_wait_us":56,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":22400,"thread_start_us":86,"threads_started":1,"update_count":3000}
I20260812 06:17:27.493497 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad): perf score=14.095187
I20260812 06:17:27.560487 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.067s	user 0.026s	sys 0.037s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":29138,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:27.561246 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad): perf score=2.188937
I20260812 06:17:27.580749 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.019s	user 0.013s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7181,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:27.581545 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling MajorDeltaCompactionOp(f7a858bb2fc740fc91314acc933a53ad): perf score=1.000000
I20260812 06:17:27.806932 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: MajorDeltaCompactionOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.225s	user 0.173s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24651797,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":881,"lbm_read_time_us":13100,"lbm_reads_lt_1ms":572,"lbm_write_time_us":45279,"lbm_writes_lt_1ms":543,"mutex_wait_us":395,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":18176,"update_count":2500}
I20260812 06:17:27.808998 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad): perf score=14.095187
I20260812 06:17:27.906762 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.098s	user 0.036s	sys 0.044s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":38196,"lbm_writes_1-10_ms":6,"lbm_writes_lt_1ms":397,"reinsert_count":0,"update_count":2000}
I20260812 06:17:27.908221 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad): perf score=2.188937
I20260812 06:17:27.924346 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.016s	user 0.002s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5595,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:27.924930 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling MajorDeltaCompactionOp(f7a858bb2fc740fc91314acc933a53ad): perf score=1.000000
I20260812 06:17:28.180249 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: MajorDeltaCompactionOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.255s	user 0.173s	sys 0.067s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24651795,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":254,"lbm_read_time_us":20967,"lbm_reads_1-10_ms":3,"lbm_reads_lt_1ms":569,"lbm_write_time_us":41179,"lbm_writes_lt_1ms":543,"mutex_wait_us":71,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5632,"update_count":2500}
I20260812 06:17:28.181094 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad): perf score=14.095187
I20260812 06:17:28.266639 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.085s	user 0.037s	sys 0.043s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":30729,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:28.267362 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad): perf score=2.188937
I20260812 06:17:28.281257 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5246,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:28.281764 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling MajorDeltaCompactionOp(f7a858bb2fc740fc91314acc933a53ad): perf score=1.000000
I20260812 06:17:28.514735 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: MajorDeltaCompactionOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.233s	user 0.135s	sys 0.084s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24651794,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1291,"lbm_read_time_us":16493,"lbm_reads_lt_1ms":572,"lbm_write_time_us":35859,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2500}
I20260812 06:17:28.515669 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad): perf score=14.095187
I20260812 06:17:28.590058 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.074s	user 0.018s	sys 0.050s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":29301,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:28.590878 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad): perf score=2.188937
I20260812 06:17:28.610903 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.020s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7412,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:28.611680 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling MajorDeltaCompactionOp(f7a858bb2fc740fc91314acc933a53ad): perf score=1.000000
I20260812 06:17:28.838250 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: MajorDeltaCompactionOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.226s	user 0.137s	sys 0.080s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24651796,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1672,"lbm_read_time_us":17300,"lbm_reads_lt_1ms":572,"lbm_write_time_us":37767,"lbm_writes_lt_1ms":543,"mutex_wait_us":392,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7296,"update_count":2500}
I20260812 06:17:28.839056 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad): perf score=11.118625
I20260812 06:17:28.890326 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.051s	user 0.039s	sys 0.008s Metrics: {"bytes_written":12717799,"delete_count":0,"lbm_write_time_us":19592,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:28.891343 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad): perf score=2.188937
I20260812 06:17:28.933369 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.042s	user 0.017s	sys 0.011s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6919,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:28.934007 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad): perf score=2.188937
I20260812 06:17:28.952162 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.018s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":7027,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:28.952970 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling MajorDeltaCompactionOp(f7a858bb2fc740fc91314acc933a53ad): perf score=1.000000
I20260812 06:17:29.182116 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: MajorDeltaCompactionOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.229s	user 0.169s	sys 0.060s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24651967,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":599,"lbm_read_time_us":17749,"lbm_reads_lt_1ms":573,"lbm_write_time_us":39853,"lbm_writes_lt_1ms":543,"mutex_wait_us":54,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":21632,"update_count":2500}
I20260812 06:17:29.183542 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad): perf score=10.126437
I20260812 06:17:29.249850 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.066s	user 0.031s	sys 0.032s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":28482,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":300,"reinsert_count":0,"update_count":1500}
I20260812 06:17:29.252404 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad): perf score=2.188937
I20260812 06:17:29.267534 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.015s	user 0.013s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5446,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:29.268741 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling FlushMRSOp(f7a858bb2fc740fc91314acc933a53ad): perf score=1.000000
I20260812 06:17:29.318850 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: FlushMRSOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.050s	user 0.041s	sys 0.009s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":137,"dirs.run_cpu_time_us":376,"dirs.run_wall_time_us":2205,"drs_written":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2714,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:29.320226 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling LogGCOp(f7a858bb2fc740fc91314acc933a53ad): free 117302571 bytes of WAL
I20260812 06:17:29.320909 12201 log_reader.cc:385] T f7a858bb2fc740fc91314acc933a53ad: removed 12 log segments from log reader
I20260812 06:17:29.320967 12201 log.cc:1079] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/f7a858bb2fc740fc91314acc933a53ad/wal-000000015 (ops 69-73)
I20260812 06:17:29.321005 12201 log.cc:1079] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/f7a858bb2fc740fc91314acc933a53ad/wal-000000016 (ops 74-78)
I20260812 06:17:29.321094 12201 log.cc:1079] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/f7a858bb2fc740fc91314acc933a53ad/wal-000000017 (ops 79-83)
I20260812 06:17:29.321131 12201 log.cc:1079] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/f7a858bb2fc740fc91314acc933a53ad/wal-000000018 (ops 84-88)
I20260812 06:17:29.321192 12201 log.cc:1079] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/f7a858bb2fc740fc91314acc933a53ad/wal-000000019 (ops 89-92)
I20260812 06:17:29.321255 12201 log.cc:1079] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/f7a858bb2fc740fc91314acc933a53ad/wal-000000020 (ops 93-97)
I20260812 06:17:29.321313 12201 log.cc:1079] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/f7a858bb2fc740fc91314acc933a53ad/wal-000000021 (ops 98-102)
I20260812 06:17:29.321359 12201 log.cc:1079] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/f7a858bb2fc740fc91314acc933a53ad/wal-000000022 (ops 103-107)
I20260812 06:17:29.321408 12201 log.cc:1079] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/f7a858bb2fc740fc91314acc933a53ad/wal-000000023 (ops 108-112)
I20260812 06:17:29.321452 12201 log.cc:1079] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/f7a858bb2fc740fc91314acc933a53ad/wal-000000024 (ops 113-116)
I20260812 06:17:29.321497 12201 log.cc:1079] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/f7a858bb2fc740fc91314acc933a53ad/wal-000000025 (ops 117-121)
I20260812 06:17:29.321540 12201 log.cc:1079] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/f7a858bb2fc740fc91314acc933a53ad/wal-000000026 (ops 122-126)
I20260812 06:17:29.350840 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: LogGCOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.030s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:17:29.351326 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad): perf score=2.188937
I20260812 06:17:29.381232 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.030s	user 0.013s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5748,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:29.382205 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling LogGCOp(f7a858bb2fc740fc91314acc933a53ad): free 11564883 bytes of WAL
I20260812 06:17:29.382638 12201 log_reader.cc:385] T f7a858bb2fc740fc91314acc933a53ad: removed 1 log segments from log reader
I20260812 06:17:29.383126 12201 log.cc:1079] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/f7a858bb2fc740fc91314acc933a53ad/wal-000000027 (ops 127-130)
I20260812 06:17:29.386919 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: LogGCOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.004s	user 0.001s	sys 0.003s Metrics: {}
I20260812 06:17:29.387457 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling UndoDeltaBlockGCOp(f7a858bb2fc740fc91314acc933a53ad): 483 bytes on disk
I20260812 06:17:29.387969 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: UndoDeltaBlockGCOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":74,"lbm_reads_lt_1ms":4}
I20260812 06:17:29.388531 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad): perf score=2.188937
I20260812 06:17:29.408526 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.020s	user 0.008s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7778,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:29.409276 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling MajorDeltaCompactionOp(f7a858bb2fc740fc91314acc933a53ad): perf score=1.000000
I20260812 06:17:29.667560 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: MajorDeltaCompactionOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.258s	user 0.194s	sys 0.063s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28754445,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1882,"lbm_read_time_us":18939,"lbm_reads_1-10_ms":1,"lbm_reads_lt_1ms":673,"lbm_write_time_us":45204,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":10880,"thread_start_us":126,"threads_started":1,"update_count":3000}
I20260812 06:17:29.668443 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad): perf score=14.095187
I20260812 06:17:29.745208 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.076s	user 0.035s	sys 0.039s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":27481,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:29.747179 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad): perf score=2.188937
I20260812 06:17:29.763731 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.016s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6288,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:29.764338 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling MajorDeltaCompactionOp(f7a858bb2fc740fc91314acc933a53ad): perf score=1.000000
I20260812 06:17:29.989213 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: MajorDeltaCompactionOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.225s	user 0.156s	sys 0.068s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24651794,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":443,"lbm_read_time_us":16446,"lbm_reads_lt_1ms":572,"lbm_write_time_us":38556,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8960,"update_count":2500}
I20260812 06:17:29.989876 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad): perf score=10.126437
I20260812 06:17:30.057927 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.068s	user 0.031s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":26475,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":300,"reinsert_count":0,"update_count":1500}
I20260812 06:17:30.058602 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad): perf score=2.188937
I20260812 06:17:30.077105 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.018s	user 0.007s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6741,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:30.077840 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling MajorDeltaCompactionOp(f7a858bb2fc740fc91314acc933a53ad): perf score=1.000000
I20260812 06:17:30.358119 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: MajorDeltaCompactionOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.280s	user 0.211s	sys 0.061s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20549382,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":613,"lbm_read_time_us":11682,"lbm_reads_lt_1ms":472,"lbm_write_time_us":52025,"lbm_writes_1-10_ms":5,"lbm_writes_lt_1ms":438,"mutex_wait_us":339,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":20992,"update_count":2000}
I20260812 06:17:30.358999 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad): perf score=10.126437
I20260812 06:17:30.422219 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.063s	user 0.026s	sys 0.016s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":19486,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:30.425784 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad): perf score=2.188937
I20260812 06:17:30.453470 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.027s	user 0.018s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7075,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:30.454970 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling MajorDeltaCompactionOp(f7a858bb2fc740fc91314acc933a53ad): perf score=1.000000
I20260812 06:17:30.671141 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: MajorDeltaCompactionOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.216s	user 0.151s	sys 0.045s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20549384,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1518,"lbm_read_time_us":13387,"lbm_reads_1-10_ms":1,"lbm_reads_lt_1ms":463,"lbm_write_time_us":39920,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":440,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2000}
I20260812 06:17:30.672272 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad): perf score=14.095187
I20260812 06:17:30.809060 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.136s	user 0.038s	sys 0.016s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":25740,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:30.811196 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad): perf score=6.157687
I20260812 06:17:30.909307 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.098s	user 0.023s	sys 0.012s Metrics: {"bytes_written":8205080,"delete_count":0,"lbm_write_time_us":15082,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:17:30.910168 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad): perf score=6.157687
I20260812 06:17:31.015509 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.105s	user 0.030s	sys 0.008s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":15505,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:17:31.016227 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad): perf score=6.157687
I20260812 06:17:31.115355 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.099s	user 0.032s	sys 0.008s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":17647,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:17:31.116106 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad): perf score=3.181125
I20260812 06:17:31.209247 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.093s	user 0.018s	sys 0.000s Metrics: {"bytes_written":4389828,"delete_count":0,"lbm_write_time_us":8218,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":109,"reinsert_count":0,"update_count":535}
I20260812 06:17:31.209940 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad): perf score=6.157687
I20260812 06:17:31.305207 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.095s	user 0.028s	sys 0.013s Metrics: {"bytes_written":7917913,"delete_count":0,"lbm_write_time_us":20536,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":195,"reinsert_count":0,"update_count":965}
I20260812 06:17:31.305804 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad): perf score=3.181125
I20260812 06:17:31.331648 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.026s	user 0.008s	sys 0.009s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":6976,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:31.332253 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad): perf score=2.188937
I20260812 06:17:31.345834 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.013s	user 0.010s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4877,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:31.346432 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling FlushMRSOp(f7a858bb2fc740fc91314acc933a53ad): perf score=1.000000
I20260812 06:17:31.390019 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: FlushMRSOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.043s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1234477,"cfile_init":1,"dirs.queue_time_us":413,"dirs.run_cpu_time_us":244,"dirs.run_wall_time_us":3198,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1968,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30,"thread_start_us":124,"threads_started":1}
I20260812 06:17:31.391093 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling LogGCOp(f7a858bb2fc740fc91314acc933a53ad): free 112692565 bytes of WAL
I20260812 06:17:31.391355 12201 log_reader.cc:385] T f7a858bb2fc740fc91314acc933a53ad: removed 11 log segments from log reader
I20260812 06:17:31.391400 12201 log.cc:1079] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/f7a858bb2fc740fc91314acc933a53ad/wal-000000028 (ops 131-135)
I20260812 06:17:31.391430 12201 log.cc:1079] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/f7a858bb2fc740fc91314acc933a53ad/wal-000000029 (ops 136-140)
I20260812 06:17:31.391494 12201 log.cc:1079] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/f7a858bb2fc740fc91314acc933a53ad/wal-000000030 (ops 141-145)
I20260812 06:17:31.391534 12201 log.cc:1079] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/f7a858bb2fc740fc91314acc933a53ad/wal-000000031 (ops 146-150)
I20260812 06:17:31.391577 12201 log.cc:1079] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/f7a858bb2fc740fc91314acc933a53ad/wal-000000032 (ops 151-155)
I20260812 06:17:31.391611 12201 log.cc:1079] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/f7a858bb2fc740fc91314acc933a53ad/wal-000000033 (ops 156-160)
I20260812 06:17:31.391670 12201 log.cc:1079] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/f7a858bb2fc740fc91314acc933a53ad/wal-000000034 (ops 161-165)
I20260812 06:17:31.391695 12201 log.cc:1079] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/f7a858bb2fc740fc91314acc933a53ad/wal-000000035 (ops 166-170)
I20260812 06:17:31.391744 12201 log.cc:1079] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/f7a858bb2fc740fc91314acc933a53ad/wal-000000036 (ops 171-175)
I20260812 06:17:31.391788 12201 log.cc:1079] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/f7a858bb2fc740fc91314acc933a53ad/wal-000000037 (ops 176-180)
I20260812 06:17:31.391827 12201 log.cc:1079] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/f7a858bb2fc740fc91314acc933a53ad/wal-000000038 (ops 181-185)
I20260812 06:17:31.420531 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: LogGCOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.029s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:17:31.421155 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling UndoDeltaBlockGCOp(f7a858bb2fc740fc91314acc933a53ad): 472 bytes on disk
I20260812 06:17:31.422120 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: UndoDeltaBlockGCOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":76,"lbm_reads_lt_1ms":4}
I20260812 06:17:31.423564 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad): perf score=3.181125
I20260812 06:17:31.442816 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.019s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":6241,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:31.443753 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling LogGCOp(f7a858bb2fc740fc91314acc933a53ad): free 12018004 bytes of WAL
I20260812 06:17:31.444082 12201 log_reader.cc:385] T f7a858bb2fc740fc91314acc933a53ad: removed 1 log segments from log reader
I20260812 06:17:31.444159 12201 log.cc:1079] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/f7a858bb2fc740fc91314acc933a53ad/wal-000000039 (ops 186-190)
I20260812 06:17:31.447083 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: LogGCOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.003s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:17:31.447733 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad): perf score=2.188937
I20260812 06:17:31.464138 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.016s	user 0.000s	sys 0.014s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6418,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:31.464851 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling MajorDeltaCompactionOp(f7a858bb2fc740fc91314acc933a53ad): perf score=1.000000
I20260812 06:17:31.754932 12081 heavy-update-compaction-itest.cc:229] Time spent updating: real 6.719s	user 2.423s	sys 0.210s
I20260812 06:17:32.010510 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: MajorDeltaCompactionOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.545s	user 0.380s	sys 0.164s Metrics: {"cfile_cache_miss":1740,"cfile_cache_miss_bytes":73881678,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":10,"delta_iterators_relevant":10,"dirs.queue_time_us":973,"lbm_read_time_us":33568,"lbm_reads_lt_1ms":1768,"lbm_write_time_us":106785,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":1744,"peak_mem_usage":212234764,"reinsert_count":0,"spinlock_wait_cycles":7680,"thread_start_us":564,"threads_started":7,"update_count":8500}
I20260812 06:17:32.012172 12271 maintenance_manager.cc:419] P 24941c49c2db48cfa47971b3e8e97cda: Scheduling FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad): perf score=18.063937
I20260812 06:17:32.020181 12081 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.265s	user 0.010s	sys 0.000s
I20260812 06:17:32.021502 12081 tablet_server.cc:179] TabletServer@127.11.204.65:0 shutting down...
I20260812 06:17:32.164518 12201 maintenance_manager.cc:643] P 24941c49c2db48cfa47971b3e8e97cda: FlushDeltaMemStoresOp(f7a858bb2fc740fc91314acc933a53ad) complete. Timing: real 0.151s	user 0.057s	sys 0.023s Metrics: {"bytes_written":20512319,"delete_count":0,"lbm_write_time_us":40310,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:17:32.165907 12081 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:32.166389 12081 tablet_replica.cc:333] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda: stopping tablet replica
I20260812 06:17:32.166770 12081 raft_consensus.cc:2243] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:32.167001 12081 raft_consensus.cc:2272] T f7a858bb2fc740fc91314acc933a53ad P 24941c49c2db48cfa47971b3e8e97cda [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:32.185505 12081 tablet_server.cc:196] TabletServer@127.11.204.65:0 shutdown complete.
I20260812 06:17:32.238739 12081 master.cc:562] Master@127.11.204.126:45153 shutting down...
I20260812 06:17:32.244987 12081 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 244a255b940e4596982a65d22f2d5920 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:32.245217 12081 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 244a255b940e4596982a65d22f2d5920 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:32.245319 12081 tablet_replica.cc:333] T 00000000000000000000000000000000 P 244a255b940e4596982a65d22f2d5920: stopping tablet replica
I20260812 06:17:32.258718 12081 master.cc:584] Master@127.11.204.126:45153 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (7790 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:32.393483 12081 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.11.204.126:37381
I20260812 06:17:32.393918 12081 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:32.397179 12317 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:32.397204 12316 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:32.397171 12319 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:32.397773 12081 server_base.cc:1061] running on GCE node
I20260812 06:17:32.398028 12081 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:32.398085 12081 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:32.398102 12081 hybrid_clock.cc:648] HybridClock initialized: now 1786515452398103 us; error 0 us; skew 500 ppm
I20260812 06:17:32.399151 12081 webserver.cc:533] Webserver started at http://127.11.204.126:34981/ using document root <none> and password file <none>
I20260812 06:17:32.399297 12081 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:32.399344 12081 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:32.399420 12081 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:32.399803 12081 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444559538-12081-0/minicluster-data/master-0-root/instance:
uuid: "ed445918db1246d499e51f577c6b58b0"
format_stamp: "Formatted at 2026-08-12 06:17:32 on dist-test-slave-dhph"
I20260812 06:17:32.401407 12081 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:32.402698 12326 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:32.403007 12081 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:32.403080 12081 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444559538-12081-0/minicluster-data/master-0-root
uuid: "ed445918db1246d499e51f577c6b58b0"
format_stamp: "Formatted at 2026-08-12 06:17:32 on dist-test-slave-dhph"
I20260812 06:17:32.403144 12081 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444559538-12081-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444559538-12081-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444559538-12081-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:32.441039 12081 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:32.441474 12081 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:32.447129 12081 rpc_server.cc:307] RPC server started. Bound to: 127.11.204.126:37381
I20260812 06:17:32.447772 12386 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.11.204.126:37381 every 8 connection(s)
I20260812 06:17:32.450244 12387 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:32.457995 12387 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P ed445918db1246d499e51f577c6b58b0: Bootstrap starting.
I20260812 06:17:32.459043 12387 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P ed445918db1246d499e51f577c6b58b0: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:32.460376 12387 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P ed445918db1246d499e51f577c6b58b0: No bootstrap required, opened a new log
I20260812 06:17:32.460937 12387 raft_consensus.cc:359] T 00000000000000000000000000000000 P ed445918db1246d499e51f577c6b58b0 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ed445918db1246d499e51f577c6b58b0" member_type: VOTER }
I20260812 06:17:32.461042 12387 raft_consensus.cc:385] T 00000000000000000000000000000000 P ed445918db1246d499e51f577c6b58b0 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:32.461066 12387 raft_consensus.cc:740] T 00000000000000000000000000000000 P ed445918db1246d499e51f577c6b58b0 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: ed445918db1246d499e51f577c6b58b0, State: Initialized, Role: FOLLOWER
I20260812 06:17:32.461227 12387 consensus_queue.cc:260] T 00000000000000000000000000000000 P ed445918db1246d499e51f577c6b58b0 [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: "ed445918db1246d499e51f577c6b58b0" member_type: VOTER }
I20260812 06:17:32.461297 12387 raft_consensus.cc:399] T 00000000000000000000000000000000 P ed445918db1246d499e51f577c6b58b0 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:32.461391 12387 raft_consensus.cc:493] T 00000000000000000000000000000000 P ed445918db1246d499e51f577c6b58b0 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:32.461453 12387 raft_consensus.cc:3060] T 00000000000000000000000000000000 P ed445918db1246d499e51f577c6b58b0 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:32.462260 12387 raft_consensus.cc:515] T 00000000000000000000000000000000 P ed445918db1246d499e51f577c6b58b0 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ed445918db1246d499e51f577c6b58b0" member_type: VOTER }
I20260812 06:17:32.462422 12387 leader_election.cc:304] T 00000000000000000000000000000000 P ed445918db1246d499e51f577c6b58b0 [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: ed445918db1246d499e51f577c6b58b0; no voters: 
I20260812 06:17:32.462730 12387 leader_election.cc:290] T 00000000000000000000000000000000 P ed445918db1246d499e51f577c6b58b0 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:32.462894 12390 raft_consensus.cc:2804] T 00000000000000000000000000000000 P ed445918db1246d499e51f577c6b58b0 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:32.463258 12387 sys_catalog.cc:565] T 00000000000000000000000000000000 P ed445918db1246d499e51f577c6b58b0 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:32.463191 12390 raft_consensus.cc:697] T 00000000000000000000000000000000 P ed445918db1246d499e51f577c6b58b0 [term 1 LEADER]: Becoming Leader. State: Replica: ed445918db1246d499e51f577c6b58b0, State: Running, Role: LEADER
I20260812 06:17:32.463460 12390 consensus_queue.cc:237] T 00000000000000000000000000000000 P ed445918db1246d499e51f577c6b58b0 [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: "ed445918db1246d499e51f577c6b58b0" member_type: VOTER }
I20260812 06:17:32.464016 12392 sys_catalog.cc:455] T 00000000000000000000000000000000 P ed445918db1246d499e51f577c6b58b0 [sys.catalog]: SysCatalogTable state changed. Reason: New leader ed445918db1246d499e51f577c6b58b0. Latest consensus state: current_term: 1 leader_uuid: "ed445918db1246d499e51f577c6b58b0" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ed445918db1246d499e51f577c6b58b0" member_type: VOTER } }
I20260812 06:17:32.464115 12392 sys_catalog.cc:458] T 00000000000000000000000000000000 P ed445918db1246d499e51f577c6b58b0 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:32.464354 12391 sys_catalog.cc:455] T 00000000000000000000000000000000 P ed445918db1246d499e51f577c6b58b0 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "ed445918db1246d499e51f577c6b58b0" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ed445918db1246d499e51f577c6b58b0" member_type: VOTER } }
I20260812 06:17:32.464516 12391 sys_catalog.cc:458] T 00000000000000000000000000000000 P ed445918db1246d499e51f577c6b58b0 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:32.464655 12399 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:32.465376 12399 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:32.465659 12081 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:32.467643 12399 catalog_manager.cc:1383] Generated new cluster ID: 3581ba0739e744e095b98ce168bbd9b1
I20260812 06:17:32.467716 12399 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:32.486294 12399 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:32.487066 12399 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:32.493603 12399 catalog_manager.cc:6092] T 00000000000000000000000000000000 P ed445918db1246d499e51f577c6b58b0: Generated new TSK 0
I20260812 06:17:32.493866 12399 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:32.498337 12081 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:32.500998 12412 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:32.500998 12415 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:32.501286 12081 server_base.cc:1061] running on GCE node
W20260812 06:17:32.501325 12417 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:32.501724 12081 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:32.501788 12081 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:32.501806 12081 hybrid_clock.cc:648] HybridClock initialized: now 1786515452501805 us; error 0 us; skew 500 ppm
I20260812 06:17:32.503022 12081 webserver.cc:533] Webserver started at http://127.11.204.65:41411/ using document root <none> and password file <none>
I20260812 06:17:32.503232 12081 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:32.503294 12081 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:32.503373 12081 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:32.503835 12081 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444559538-12081-0/minicluster-data/ts-0-root/instance:
uuid: "8181fb8421984b6fa7cdf2f68cef380d"
format_stamp: "Formatted at 2026-08-12 06:17:32 on dist-test-slave-dhph"
I20260812 06:17:32.506021 12081 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:32.507351 12422 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:32.507761 12081 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:32.507875 12081 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444559538-12081-0/minicluster-data/ts-0-root
uuid: "8181fb8421984b6fa7cdf2f68cef380d"
format_stamp: "Formatted at 2026-08-12 06:17:32 on dist-test-slave-dhph"
I20260812 06:17:32.507958 12081 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444559538-12081-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444559538-12081-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444559538-12081-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:32.518532 12081 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:32.519225 12081 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:32.519572 12081 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:32.520501 12081 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:32.520558 12081 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:32.520597 12081 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:32.520613 12081 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:32.527061 12081 rpc_server.cc:307] RPC server started. Bound to: 127.11.204.65:37097
I20260812 06:17:32.527175 12502 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.11.204.65:37097 every 8 connection(s)
I20260812 06:17:32.541237 12503 heartbeater.cc:344] Connected to a master server at 127.11.204.126:37381
I20260812 06:17:32.541391 12503 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:32.541706 12503 heartbeater.cc:507] Master 127.11.204.126:37381 requested a full tablet report, sending...
I20260812 06:17:32.542795 12345 ts_manager.cc:194] Registered new tserver with Master: 8181fb8421984b6fa7cdf2f68cef380d (127.11.204.65:37097)
I20260812 06:17:32.543208 12081 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.015572224s
I20260812 06:17:32.544143 12345 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:46654
I20260812 06:17:32.554883 12345 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:46668:
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:32.567045 12456 tablet_service.cc:1511] Processing CreateTablet for tablet ea4b08fb3c7e4b18a564a6823d89158f (DEFAULT_TABLE table=heavy-update-compaction-test [id=aa04554e22b0479eb880fd0859e56253]), partition=
I20260812 06:17:32.567391 12456 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet ea4b08fb3c7e4b18a564a6823d89158f. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:32.570529 12515 tablet_bootstrap.cc:492] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d: Bootstrap starting.
I20260812 06:17:32.571748 12515 tablet_bootstrap.cc:654] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:32.573853 12515 tablet_bootstrap.cc:492] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d: No bootstrap required, opened a new log
I20260812 06:17:32.573957 12515 ts_tablet_manager.cc:1403] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:17:32.574535 12515 raft_consensus.cc:359] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8181fb8421984b6fa7cdf2f68cef380d" member_type: VOTER last_known_addr { host: "127.11.204.65" port: 37097 } }
I20260812 06:17:32.574729 12515 raft_consensus.cc:385] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:32.574784 12515 raft_consensus.cc:740] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 8181fb8421984b6fa7cdf2f68cef380d, State: Initialized, Role: FOLLOWER
I20260812 06:17:32.574965 12515 consensus_queue.cc:260] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d [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: "8181fb8421984b6fa7cdf2f68cef380d" member_type: VOTER last_known_addr { host: "127.11.204.65" port: 37097 } }
I20260812 06:17:32.575063 12515 raft_consensus.cc:399] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:32.575114 12515 raft_consensus.cc:493] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:32.575342 12515 raft_consensus.cc:3060] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:32.576347 12515 raft_consensus.cc:515] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8181fb8421984b6fa7cdf2f68cef380d" member_type: VOTER last_known_addr { host: "127.11.204.65" port: 37097 } }
I20260812 06:17:32.576556 12515 leader_election.cc:304] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d [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: 8181fb8421984b6fa7cdf2f68cef380d; no voters: 
I20260812 06:17:32.576844 12515 leader_election.cc:290] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:32.577116 12517 raft_consensus.cc:2804] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:32.577252 12515 ts_tablet_manager.cc:1434] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d: Time spent starting tablet: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:17:32.577291 12503 heartbeater.cc:499] Master 127.11.204.126:37381 was elected leader, sending a full tablet report...
I20260812 06:17:32.577517 12517 raft_consensus.cc:697] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d [term 1 LEADER]: Becoming Leader. State: Replica: 8181fb8421984b6fa7cdf2f68cef380d, State: Running, Role: LEADER
I20260812 06:17:32.577680 12517 consensus_queue.cc:237] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d [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: "8181fb8421984b6fa7cdf2f68cef380d" member_type: VOTER last_known_addr { host: "127.11.204.65" port: 37097 } }
I20260812 06:17:32.579478 12345 catalog_manager.cc:5719] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d reported cstate change: term changed from 0 to 1, leader changed from <none> to 8181fb8421984b6fa7cdf2f68cef380d (127.11.204.65). New cstate: current_term: 1 leader_uuid: "8181fb8421984b6fa7cdf2f68cef380d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8181fb8421984b6fa7cdf2f68cef380d" member_type: VOTER last_known_addr { host: "127.11.204.65" port: 37097 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:32.656919 12081 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.071s	user 0.026s	sys 0.008s
I20260812 06:17:32.779054 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling FlushMRSOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=13.101815
I20260812 06:17:32.932364 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: FlushMRSOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.153s	user 0.107s	sys 0.032s Metrics: {"bytes_written":8205077,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":135,"dirs.run_cpu_time_us":331,"dirs.run_wall_time_us":1335,"drs_written":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4,"lbm_write_time_us":31913,"lbm_writes_lt_1ms":557,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"update_count":1000}
I20260812 06:17:32.933255 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling LogGCOp(ea4b08fb3c7e4b18a564a6823d89158f): free 8725963 bytes of WAL
I20260812 06:17:32.933650 12429 log_reader.cc:385] T ea4b08fb3c7e4b18a564a6823d89158f: removed 1 log segments from log reader
I20260812 06:17:32.933732 12429 log.cc:1079] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/ea4b08fb3c7e4b18a564a6823d89158f/wal-000000001 (ops 1-6)
I20260812 06:17:32.936343 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: LogGCOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:17:32.936993 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling UndoDeltaBlockGCOp(ea4b08fb3c7e4b18a564a6823d89158f): 12308959 bytes on disk
I20260812 06:17:32.937564 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: UndoDeltaBlockGCOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":82,"lbm_reads_lt_1ms":4}
I20260812 06:17:32.938572 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=2.188937
I20260812 06:17:32.966989 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.028s	user 0.014s	sys 0.013s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":10719,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:32.967525 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling MajorDeltaCompactionOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=1.000000
I20260812 06:17:33.129315 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: MajorDeltaCompactionOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.160s	user 0.100s	sys 0.043s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16528898,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":3512,"lbm_read_time_us":10133,"lbm_reads_lt_1ms":360,"lbm_write_time_us":25469,"lbm_writes_lt_1ms":343,"mutex_wait_us":28,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":3456,"thread_start_us":1668,"threads_started":5,"update_count":1500}
I20260812 06:17:33.130255 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=10.126437
I20260812 06:17:33.196463 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.066s	user 0.034s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20906,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:33.197088 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=2.188937
I20260812 06:17:33.212785 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.015s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4732,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:33.213688 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling MajorDeltaCompactionOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=1.000000
I20260812 06:17:33.379298 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: MajorDeltaCompactionOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.165s	user 0.114s	sys 0.050s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1075,"lbm_read_time_us":13136,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27716,"lbm_writes_lt_1ms":443,"mutex_wait_us":266,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2000}
I20260812 06:17:33.380118 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=10.126437
I20260812 06:17:33.442775 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.062s	user 0.024s	sys 0.025s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":22244,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:33.443423 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=2.188937
I20260812 06:17:33.456946 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.013s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5048,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:33.457813 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling MajorDeltaCompactionOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=1.000000
I20260812 06:17:33.602555 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: MajorDeltaCompactionOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.145s	user 0.116s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":415,"lbm_read_time_us":12037,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26575,"lbm_writes_lt_1ms":443,"mutex_wait_us":26,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":34304,"update_count":2000}
I20260812 06:17:33.603559 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=10.126437
I20260812 06:17:33.661465 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.058s	user 0.038s	sys 0.010s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":23513,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:33.662057 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=2.188937
I20260812 06:17:33.676875 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5280,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:33.677726 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling MajorDeltaCompactionOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=1.000000
I20260812 06:17:33.829094 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: MajorDeltaCompactionOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.151s	user 0.120s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":372,"lbm_read_time_us":12656,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28242,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4224,"update_count":2000}
I20260812 06:17:33.829977 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=10.126437
I20260812 06:17:33.898187 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.068s	user 0.044s	sys 0.018s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":22304,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:33.898904 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=2.188937
I20260812 06:17:33.913291 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5677,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:33.913967 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling MajorDeltaCompactionOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=1.000000
I20260812 06:17:34.145632 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: MajorDeltaCompactionOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.231s	user 0.135s	sys 0.094s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1286,"lbm_read_time_us":18398,"lbm_reads_lt_1ms":472,"lbm_write_time_us":34706,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":437,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4736,"update_count":2000}
I20260812 06:17:34.146214 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=11.118625
I20260812 06:17:34.201010 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.055s	user 0.028s	sys 0.024s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":23686,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:34.201601 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=2.188937
I20260812 06:17:34.221029 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.019s	user 0.008s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6743,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:34.221601 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling MajorDeltaCompactionOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=1.000000
I20260812 06:17:34.380074 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: MajorDeltaCompactionOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.158s	user 0.135s	sys 0.023s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631303,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1015,"lbm_read_time_us":10024,"lbm_reads_lt_1ms":464,"lbm_write_time_us":30977,"lbm_writes_lt_1ms":443,"mutex_wait_us":30,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9984,"update_count":2000}
I20260812 06:17:34.381119 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=10.126437
I20260812 06:17:34.423177 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.042s	user 0.026s	sys 0.015s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":18237,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:34.423777 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=2.188937
I20260812 06:17:34.441843 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.018s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6677,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:34.442572 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling FlushMRSOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=1.000000
I20260812 06:17:34.503518 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: FlushMRSOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.061s	user 0.028s	sys 0.005s Metrics: {"bytes_written":1152509,"cfile_init":1,"dirs.queue_time_us":113,"dirs.run_cpu_time_us":266,"dirs.run_wall_time_us":2323,"drs_written":1,"lbm_read_time_us":86,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1971,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:34.504508 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling LogGCOp(ea4b08fb3c7e4b18a564a6823d89158f): free 111786202 bytes of WAL
I20260812 06:17:34.505019 12429 log_reader.cc:385] T ea4b08fb3c7e4b18a564a6823d89158f: removed 11 log segments from log reader
I20260812 06:17:34.505244 12429 log.cc:1079] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/ea4b08fb3c7e4b18a564a6823d89158f/wal-000000002 (ops 7-11)
I20260812 06:17:34.505364 12429 log.cc:1079] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/ea4b08fb3c7e4b18a564a6823d89158f/wal-000000003 (ops 12-16)
I20260812 06:17:34.505442 12429 log.cc:1079] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/ea4b08fb3c7e4b18a564a6823d89158f/wal-000000004 (ops 17-20)
I20260812 06:17:34.505496 12429 log.cc:1079] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/ea4b08fb3c7e4b18a564a6823d89158f/wal-000000005 (ops 21-25)
I20260812 06:17:34.505544 12429 log.cc:1079] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/ea4b08fb3c7e4b18a564a6823d89158f/wal-000000006 (ops 26-30)
I20260812 06:17:34.505594 12429 log.cc:1079] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/ea4b08fb3c7e4b18a564a6823d89158f/wal-000000007 (ops 31-35)
I20260812 06:17:34.505643 12429 log.cc:1079] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/ea4b08fb3c7e4b18a564a6823d89158f/wal-000000008 (ops 36-40)
I20260812 06:17:34.505692 12429 log.cc:1079] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/ea4b08fb3c7e4b18a564a6823d89158f/wal-000000009 (ops 41-44)
I20260812 06:17:34.505739 12429 log.cc:1079] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/ea4b08fb3c7e4b18a564a6823d89158f/wal-000000010 (ops 45-49)
I20260812 06:17:34.505786 12429 log.cc:1079] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/ea4b08fb3c7e4b18a564a6823d89158f/wal-000000011 (ops 50-54)
I20260812 06:17:34.505846 12429 log.cc:1079] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/ea4b08fb3c7e4b18a564a6823d89158f/wal-000000012 (ops 55-59)
I20260812 06:17:34.535755 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: LogGCOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.031s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:17:34.536266 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling UndoDeltaBlockGCOp(ea4b08fb3c7e4b18a564a6823d89158f): 447 bytes on disk
I20260812 06:17:34.536842 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: UndoDeltaBlockGCOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":84,"lbm_reads_lt_1ms":4}
I20260812 06:17:34.537796 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=6.157687
I20260812 06:17:34.565703 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.028s	user 0.025s	sys 0.000s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":12104,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:17:34.566334 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling LogGCOp(ea4b08fb3c7e4b18a564a6823d89158f): free 8767172 bytes of WAL
I20260812 06:17:34.566602 12429 log_reader.cc:385] T ea4b08fb3c7e4b18a564a6823d89158f: removed 1 log segments from log reader
I20260812 06:17:34.566686 12429 log.cc:1079] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/ea4b08fb3c7e4b18a564a6823d89158f/wal-000000013 (ops 60-64)
I20260812 06:17:34.568480 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: LogGCOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:17:34.568861 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=2.188937
I20260812 06:17:34.586464 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.017s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5824,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:34.587543 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling MajorDeltaCompactionOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=1.000000
I20260812 06:17:34.862342 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: MajorDeltaCompactionOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.275s	user 0.200s	sys 0.061s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32938785,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":640,"lbm_read_time_us":18432,"lbm_reads_lt_1ms":770,"lbm_write_time_us":52282,"lbm_writes_lt_1ms":743,"mutex_wait_us":414,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":188928,"thread_start_us":94,"threads_started":1,"update_count":3500}
I20260812 06:17:34.862995 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=18.063937
I20260812 06:17:34.961735 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.098s	user 0.048s	sys 0.044s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":37349,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":501,"reinsert_count":0,"update_count":2500}
I20260812 06:17:34.962363 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=2.188937
I20260812 06:17:34.999176 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.037s	user 0.016s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7583,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:34.999956 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=2.188937
I20260812 06:17:35.015210 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.015s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5214,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.016383 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling MajorDeltaCompactionOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=1.000000
I20260812 06:17:35.321374 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: MajorDeltaCompactionOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.305s	user 0.193s	sys 0.104s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32938671,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":155,"lbm_read_time_us":22658,"lbm_reads_lt_1ms":773,"lbm_write_time_us":48586,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":742,"mutex_wait_us":25,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":28928,"update_count":3500}
I20260812 06:17:35.322546 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=18.063937
I20260812 06:17:35.410274 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.087s	user 0.059s	sys 0.024s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":37053,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:17:35.411270 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=2.188937
I20260812 06:17:35.431607 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.020s	user 0.015s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7694,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.432547 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling MajorDeltaCompactionOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=1.000000
I20260812 06:17:35.689981 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: MajorDeltaCompactionOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.257s	user 0.177s	sys 0.080s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28836137,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":149,"lbm_read_time_us":14874,"lbm_reads_lt_1ms":664,"lbm_write_time_us":44614,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":642,"mutex_wait_us":51,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:17:35.690828 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=15.087375
I20260812 06:17:35.770742 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.080s	user 0.042s	sys 0.033s Metrics: {"bytes_written":16820139,"delete_count":0,"lbm_write_time_us":32826,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:17:35.771788 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=2.188937
I20260812 06:17:35.788367 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.016s	user 0.009s	sys 0.003s Metrics: {"bytes_written":4102660,"delete_count":0,"lbm_write_time_us":5497,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.788923 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=2.188937
I20260812 06:17:35.804422 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5859,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:35.805013 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling MajorDeltaCompactionOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=1.000000
I20260812 06:17:36.068437 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: MajorDeltaCompactionOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.263s	user 0.159s	sys 0.103s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28836239,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":2546,"lbm_read_time_us":18780,"lbm_reads_lt_1ms":673,"lbm_write_time_us":45113,"lbm_writes_lt_1ms":643,"mutex_wait_us":666,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":3000}
I20260812 06:17:36.069270 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=15.087375
I20260812 06:17:36.147004 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.078s	user 0.033s	sys 0.039s Metrics: {"bytes_written":16820141,"delete_count":0,"lbm_write_time_us":32544,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":412,"reinsert_count":0,"update_count":2050}
I20260812 06:17:36.147764 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=2.188937
I20260812 06:17:36.170459 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.022s	user 0.005s	sys 0.012s 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:36.171072 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=2.188937
I20260812 06:17:36.184576 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.013s	user 0.011s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4670,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:36.185178 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling MajorDeltaCompactionOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=1.000000
I20260812 06:17:36.424597 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: MajorDeltaCompactionOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.239s	user 0.170s	sys 0.067s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28836240,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":320,"lbm_read_time_us":16741,"lbm_reads_lt_1ms":673,"lbm_write_time_us":38269,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":22272,"update_count":3000}
I20260812 06:17:36.425359 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=14.095187
I20260812 06:17:36.500908 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.075s	user 0.025s	sys 0.047s Metrics: {"bytes_written":16409897,"delete_count":0,"lbm_write_time_us":36125,"lbm_writes_1-10_ms":5,"lbm_writes_lt_1ms":398,"reinsert_count":0,"update_count":2000}
I20260812 06:17:36.501578 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=2.188937
I20260812 06:17:36.523944 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.022s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6166,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:36.524564 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling FlushMRSOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=1.000000
I20260812 06:17:36.591104 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: FlushMRSOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.066s	user 0.038s	sys 0.004s Metrics: {"bytes_written":1357580,"cfile_init":1,"dirs.queue_time_us":107,"dirs.run_cpu_time_us":450,"dirs.run_wall_time_us":2283,"drs_written":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2108,"lbm_writes_lt_1ms":44,"peak_mem_usage":0,"rows_written":33}
I20260812 06:17:36.591913 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling LogGCOp(ea4b08fb3c7e4b18a564a6823d89158f): free 132571307 bytes of WAL
I20260812 06:17:36.592327 12429 log_reader.cc:385] T ea4b08fb3c7e4b18a564a6823d89158f: removed 13 log segments from log reader
I20260812 06:17:36.592418 12429 log.cc:1079] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/ea4b08fb3c7e4b18a564a6823d89158f/wal-000000014 (ops 65-68)
I20260812 06:17:36.592491 12429 log.cc:1079] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/ea4b08fb3c7e4b18a564a6823d89158f/wal-000000015 (ops 69-73)
I20260812 06:17:36.592541 12429 log.cc:1079] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/ea4b08fb3c7e4b18a564a6823d89158f/wal-000000016 (ops 74-78)
I20260812 06:17:36.592590 12429 log.cc:1079] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/ea4b08fb3c7e4b18a564a6823d89158f/wal-000000017 (ops 79-82)
I20260812 06:17:36.592633 12429 log.cc:1079] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/ea4b08fb3c7e4b18a564a6823d89158f/wal-000000018 (ops 83-87)
I20260812 06:17:36.592679 12429 log.cc:1079] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/ea4b08fb3c7e4b18a564a6823d89158f/wal-000000019 (ops 88-92)
I20260812 06:17:36.592722 12429 log.cc:1079] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/ea4b08fb3c7e4b18a564a6823d89158f/wal-000000020 (ops 93-97)
I20260812 06:17:36.592752 12429 log.cc:1079] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/ea4b08fb3c7e4b18a564a6823d89158f/wal-000000021 (ops 98-102)
I20260812 06:17:36.592937 12429 log.cc:1079] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/ea4b08fb3c7e4b18a564a6823d89158f/wal-000000022 (ops 103-107)
I20260812 06:17:36.593015 12429 log.cc:1079] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/ea4b08fb3c7e4b18a564a6823d89158f/wal-000000023 (ops 108-112)
I20260812 06:17:36.593065 12429 log.cc:1079] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/ea4b08fb3c7e4b18a564a6823d89158f/wal-000000024 (ops 113-117)
I20260812 06:17:36.593111 12429 log.cc:1079] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/ea4b08fb3c7e4b18a564a6823d89158f/wal-000000025 (ops 118-122)
I20260812 06:17:36.593156 12429 log.cc:1079] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/ea4b08fb3c7e4b18a564a6823d89158f/wal-000000026 (ops 123-127)
I20260812 06:17:36.627100 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: LogGCOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.035s	user 0.000s	sys 0.034s Metrics: {}
I20260812 06:17:36.628063 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling UndoDeltaBlockGCOp(ea4b08fb3c7e4b18a564a6823d89158f): 508 bytes on disk
I20260812 06:17:36.628631 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: UndoDeltaBlockGCOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4}
I20260812 06:17:36.629240 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=6.157687
I20260812 06:17:36.652335 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.023s	user 0.009s	sys 0.012s Metrics: {"bytes_written":8205079,"delete_count":0,"lbm_write_time_us":9431,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:17:36.652840 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=2.188937
I20260812 06:17:36.664551 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4150,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:36.665295 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling MajorDeltaCompactionOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=1.000000
I20260812 06:17:36.963020 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: MajorDeltaCompactionOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.297s	user 0.219s	sys 0.077s Metrics: {"cfile_cache_miss":834,"cfile_cache_miss_bytes":37041195,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1505,"lbm_read_time_us":18396,"lbm_reads_lt_1ms":874,"lbm_write_time_us":56208,"lbm_writes_lt_1ms":843,"mutex_wait_us":71,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":18816,"thread_start_us":383,"threads_started":6,"update_count":4000}
I20260812 06:17:36.964025 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=18.063937
I20260812 06:17:37.033270 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.069s	user 0.043s	sys 0.023s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":29771,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:37.034389 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=2.188937
I20260812 06:17:37.057498 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.023s	user 0.009s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":7090,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:37.058210 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling MajorDeltaCompactionOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=1.000000
I20260812 06:17:37.272024 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: MajorDeltaCompactionOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.214s	user 0.170s	sys 0.043s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28836138,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":530,"lbm_read_time_us":16043,"lbm_reads_lt_1ms":668,"lbm_write_time_us":44933,"lbm_writes_lt_1ms":643,"mutex_wait_us":300,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":11776,"update_count":3000}
I20260812 06:17:37.273000 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=14.095187
I20260812 06:17:37.332044 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.059s	user 0.041s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25574,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:37.332733 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=2.188937
I20260812 06:17:37.365607 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.033s	user 0.012s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6770,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:37.366503 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=2.188937
I20260812 06:17:37.382933 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.016s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5053,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:37.383453 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling MajorDeltaCompactionOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=1.000000
I20260812 06:17:37.716584 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: MajorDeltaCompactionOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.333s	user 0.248s	sys 0.064s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28836254,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1890,"lbm_read_time_us":21929,"lbm_reads_1-10_ms":1,"lbm_reads_lt_1ms":672,"lbm_write_time_us":55432,"lbm_writes_lt_1ms":643,"mutex_wait_us":205,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6656,"update_count":3000}
I20260812 06:17:37.717954 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=22.032687
I20260812 06:17:37.830425 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.112s	user 0.058s	sys 0.048s Metrics: {"bytes_written":24614753,"delete_count":0,"lbm_write_time_us":48411,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":600,"reinsert_count":0,"update_count":3000}
I20260812 06:17:37.831724 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=2.188937
I20260812 06:17:37.859499 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.027s	user 0.016s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":9033,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:37.860293 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling MajorDeltaCompactionOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=1.000000
I20260812 06:17:38.162493 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: MajorDeltaCompactionOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.302s	user 0.213s	sys 0.081s Metrics: {"cfile_cache_miss":732,"cfile_cache_miss_bytes":32938575,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":420,"lbm_read_time_us":25460,"lbm_reads_lt_1ms":764,"lbm_write_time_us":65338,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":742,"mutex_wait_us":47,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":23680,"update_count":3500}
I20260812 06:17:38.163275 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=18.063937
I20260812 06:17:38.249025 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.086s	user 0.052s	sys 0.031s Metrics: {"bytes_written":20512343,"delete_count":0,"lbm_write_time_us":33015,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:38.251019 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=2.188937
I20260812 06:17:38.295084 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.044s	user 0.019s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":10862,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:38.295665 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=2.188937
I20260812 06:17:38.314852 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.019s	user 0.019s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6982,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:38.316056 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling FlushMRSOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=1.000000
I20260812 06:17:38.354569 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: FlushMRSOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.038s	user 0.036s	sys 0.000s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":64,"dirs.run_cpu_time_us":270,"dirs.run_wall_time_us":1895,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2275,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:38.355376 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling LogGCOp(ea4b08fb3c7e4b18a564a6823d89158f): free 120553581 bytes of WAL
I20260812 06:17:38.355624 12429 log_reader.cc:385] T ea4b08fb3c7e4b18a564a6823d89158f: removed 12 log segments from log reader
I20260812 06:17:38.355671 12429 log.cc:1079] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/ea4b08fb3c7e4b18a564a6823d89158f/wal-000000027 (ops 128-132)
I20260812 06:17:38.355705 12429 log.cc:1079] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/ea4b08fb3c7e4b18a564a6823d89158f/wal-000000028 (ops 133-137)
I20260812 06:17:38.356118 12429 log.cc:1079] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/ea4b08fb3c7e4b18a564a6823d89158f/wal-000000029 (ops 138-142)
I20260812 06:17:38.356184 12429 log.cc:1079] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/ea4b08fb3c7e4b18a564a6823d89158f/wal-000000030 (ops 143-146)
I20260812 06:17:38.356204 12429 log.cc:1079] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/ea4b08fb3c7e4b18a564a6823d89158f/wal-000000031 (ops 147-151)
I20260812 06:17:38.356240 12429 log.cc:1079] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/ea4b08fb3c7e4b18a564a6823d89158f/wal-000000032 (ops 152-156)
I20260812 06:17:38.356266 12429 log.cc:1079] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/ea4b08fb3c7e4b18a564a6823d89158f/wal-000000033 (ops 157-160)
I20260812 06:17:38.357334 12429 log.cc:1079] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/ea4b08fb3c7e4b18a564a6823d89158f/wal-000000034 (ops 161-165)
I20260812 06:17:38.357402 12429 log.cc:1079] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/ea4b08fb3c7e4b18a564a6823d89158f/wal-000000035 (ops 166-170)
I20260812 06:17:38.357424 12429 log.cc:1079] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/ea4b08fb3c7e4b18a564a6823d89158f/wal-000000036 (ops 171-175)
I20260812 06:17:38.357443 12429 log.cc:1079] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/ea4b08fb3c7e4b18a564a6823d89158f/wal-000000037 (ops 176-180)
I20260812 06:17:38.357461 12429 log.cc:1079] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d: Deleting log segment in path: /tmp/dist-test-taskIgxuzq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515444559538-12081-0/minicluster-data/ts-0-root/wals/ea4b08fb3c7e4b18a564a6823d89158f/wal-000000038 (ops 181-185)
I20260812 06:17:38.389915 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: LogGCOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.034s	user 0.000s	sys 0.031s Metrics: {}
I20260812 06:17:38.390352 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=3.181125
I20260812 06:17:38.417688 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.027s	user 0.013s	sys 0.008s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":9123,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:38.418505 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling UndoDeltaBlockGCOp(ea4b08fb3c7e4b18a564a6823d89158f): 448 bytes on disk
I20260812 06:17:38.419034 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: UndoDeltaBlockGCOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":76,"lbm_reads_lt_1ms":4}
I20260812 06:17:38.419636 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=2.188937
I20260812 06:17:38.433684 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.014s	user 0.010s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5107,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:38.434275 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling MajorDeltaCompactionOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=1.000000
I20260812 06:17:38.736123 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: MajorDeltaCompactionOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.302s	user 0.237s	sys 0.061s Metrics: {"cfile_cache_miss":935,"cfile_cache_miss_bytes":41143748,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":1583,"lbm_read_time_us":19934,"lbm_reads_lt_1ms":975,"lbm_write_time_us":63993,"lbm_writes_lt_1ms":943,"peak_mem_usage":112822188,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":595,"threads_started":6,"update_count":4500}
I20260812 06:17:38.737011 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=19.056125
I20260812 06:17:38.770874 12081 heavy-update-compaction-itest.cc:229] Time spent updating: real 6.113s	user 2.291s	sys 0.117s
I20260812 06:17:38.837857 12081 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.067s	user 0.000s	sys 0.000s
I20260812 06:17:38.838534 12081 tablet_server.cc:179] TabletServer@127.11.204.65:0 shutting down...
I20260812 06:17:38.844106 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.107s	user 0.061s	sys 0.044s Metrics: {"bytes_written":20922555,"delete_count":0,"lbm_write_time_us":46619,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":512,"reinsert_count":0,"update_count":2550}
I20260812 06:17:38.844926 12504 maintenance_manager.cc:419] P 8181fb8421984b6fa7cdf2f68cef380d: Scheduling FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f): perf score=2.188937
I20260812 06:17:38.859244 12429 maintenance_manager.cc:643] P 8181fb8421984b6fa7cdf2f68cef380d: FlushDeltaMemStoresOp(ea4b08fb3c7e4b18a564a6823d89158f) complete. Timing: real 0.014s	user 0.010s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5232,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:38.860160 12081 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:38.860436 12081 tablet_replica.cc:333] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d: stopping tablet replica
I20260812 06:17:38.860596 12081 raft_consensus.cc:2243] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:38.860797 12081 raft_consensus.cc:2272] T ea4b08fb3c7e4b18a564a6823d89158f P 8181fb8421984b6fa7cdf2f68cef380d [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:38.868993 12081 tablet_server.cc:196] TabletServer@127.11.204.65:0 shutdown complete.
I20260812 06:17:38.874444 12081 master.cc:562] Master@127.11.204.126:37381 shutting down...
I20260812 06:17:38.882169 12081 raft_consensus.cc:2243] T 00000000000000000000000000000000 P ed445918db1246d499e51f577c6b58b0 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:38.882405 12081 raft_consensus.cc:2272] T 00000000000000000000000000000000 P ed445918db1246d499e51f577c6b58b0 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:38.882463 12081 tablet_replica.cc:333] T 00000000000000000000000000000000 P ed445918db1246d499e51f577c6b58b0: stopping tablet replica
I20260812 06:17:38.896613 12081 master.cc:584] Master@127.11.204.126:37381 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (6661 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (14453 ms total)

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