[==========] 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:20:16.656461  5862 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.5.185.190:45475
I20260812 06:20:16.657612  5862 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:20:16.658252  5862 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:16.665141  5871 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:20:16.665175  5869 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:20:16.665380  5862 server_base.cc:1061] running on GCE node
W20260812 06:20:16.665416  5874 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:20:16.665941  5862 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:16.666036  5862 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:20:16.666064  5862 hybrid_clock.cc:648] HybridClock initialized: now 1786515616666062 us; error 0 us; skew 500 ppm
I20260812 06:20:16.667981  5862 webserver.cc:533] Webserver started at http://127.5.185.190:41855/ using document root <none> and password file <none>
I20260812 06:20:16.668531  5862 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:16.668588  5862 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:16.668826  5862 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:16.670492  5862 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616645234-5862-0/minicluster-data/master-0-root/instance:
uuid: "9a071e225c1d44b887324d77196e9833"
format_stamp: "Formatted at 2026-08-12 06:20:16 on dist-test-slave-jpj1"
I20260812 06:20:16.674033  5862 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.005s	sys 0.000s
I20260812 06:20:16.676108  5881 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:20:16.677102  5862 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:16.677204  5862 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616645234-5862-0/minicluster-data/master-0-root
uuid: "9a071e225c1d44b887324d77196e9833"
format_stamp: "Formatted at 2026-08-12 06:20:16 on dist-test-slave-jpj1"
I20260812 06:20:16.677301  5862 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616645234-5862-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616645234-5862-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616645234-5862-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:20:16.699338  5862 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:16.700271  5862 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:20:16.700604  5862 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:16.712864  5862 rpc_server.cc:307] RPC server started. Bound to: 127.5.185.190:45475
I20260812 06:20:16.712895  5973 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.5.185.190:45475 every 8 connection(s)
I20260812 06:20:16.715463  5974 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:20:16.722005  5974 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 9a071e225c1d44b887324d77196e9833: Bootstrap starting.
I20260812 06:20:16.724493  5974 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 9a071e225c1d44b887324d77196e9833: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:16.725445  5974 log.cc:826] T 00000000000000000000000000000000 P 9a071e225c1d44b887324d77196e9833: Log is configured to *not* fsync() on all Append() calls
I20260812 06:20:16.727289  5974 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 9a071e225c1d44b887324d77196e9833: No bootstrap required, opened a new log
I20260812 06:20:16.730216  5974 raft_consensus.cc:359] T 00000000000000000000000000000000 P 9a071e225c1d44b887324d77196e9833 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9a071e225c1d44b887324d77196e9833" member_type: VOTER }
I20260812 06:20:16.730396  5974 raft_consensus.cc:385] T 00000000000000000000000000000000 P 9a071e225c1d44b887324d77196e9833 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:16.730441  5974 raft_consensus.cc:740] T 00000000000000000000000000000000 P 9a071e225c1d44b887324d77196e9833 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 9a071e225c1d44b887324d77196e9833, State: Initialized, Role: FOLLOWER
I20260812 06:20:16.731113  5974 consensus_queue.cc:260] T 00000000000000000000000000000000 P 9a071e225c1d44b887324d77196e9833 [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: "9a071e225c1d44b887324d77196e9833" member_type: VOTER }
I20260812 06:20:16.731281  5974 raft_consensus.cc:399] T 00000000000000000000000000000000 P 9a071e225c1d44b887324d77196e9833 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:16.731352  5974 raft_consensus.cc:493] T 00000000000000000000000000000000 P 9a071e225c1d44b887324d77196e9833 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:16.731485  5974 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 9a071e225c1d44b887324d77196e9833 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:16.732360  5974 raft_consensus.cc:515] T 00000000000000000000000000000000 P 9a071e225c1d44b887324d77196e9833 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9a071e225c1d44b887324d77196e9833" member_type: VOTER }
I20260812 06:20:16.732841  5974 leader_election.cc:304] T 00000000000000000000000000000000 P 9a071e225c1d44b887324d77196e9833 [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: 9a071e225c1d44b887324d77196e9833; no voters: 
I20260812 06:20:16.733184  5974 leader_election.cc:290] T 00000000000000000000000000000000 P 9a071e225c1d44b887324d77196e9833 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:16.733353  5980 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 9a071e225c1d44b887324d77196e9833 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:16.733610  5980 raft_consensus.cc:697] T 00000000000000000000000000000000 P 9a071e225c1d44b887324d77196e9833 [term 1 LEADER]: Becoming Leader. State: Replica: 9a071e225c1d44b887324d77196e9833, State: Running, Role: LEADER
I20260812 06:20:16.734045  5980 consensus_queue.cc:237] T 00000000000000000000000000000000 P 9a071e225c1d44b887324d77196e9833 [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: "9a071e225c1d44b887324d77196e9833" member_type: VOTER }
I20260812 06:20:16.734303  5974 sys_catalog.cc:565] T 00000000000000000000000000000000 P 9a071e225c1d44b887324d77196e9833 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:16.736112  5986 sys_catalog.cc:455] T 00000000000000000000000000000000 P 9a071e225c1d44b887324d77196e9833 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 9a071e225c1d44b887324d77196e9833. Latest consensus state: current_term: 1 leader_uuid: "9a071e225c1d44b887324d77196e9833" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9a071e225c1d44b887324d77196e9833" member_type: VOTER } }
I20260812 06:20:16.736203  5981 sys_catalog.cc:455] T 00000000000000000000000000000000 P 9a071e225c1d44b887324d77196e9833 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "9a071e225c1d44b887324d77196e9833" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9a071e225c1d44b887324d77196e9833" member_type: VOTER } }
I20260812 06:20:16.736276  5986 sys_catalog.cc:458] T 00000000000000000000000000000000 P 9a071e225c1d44b887324d77196e9833 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:16.736276  5981 sys_catalog.cc:458] T 00000000000000000000000000000000 P 9a071e225c1d44b887324d77196e9833 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:16.736723  5997 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:16.739503  5997 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:16.739806  5862 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:16.744900  5997 catalog_manager.cc:1383] Generated new cluster ID: 3f98a12b0bba4be0abff7eee76835fde
I20260812 06:20:16.744977  5997 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:16.762956  5997 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:16.764240  5997 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:16.776290  5997 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 9a071e225c1d44b887324d77196e9833: Generated new TSK 0
I20260812 06:20:16.777187  5997 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:16.804865  5862 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:16.807639  6012 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:20:16.807674  6015 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:16.807730  6011 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:20:16.808108  5862 server_base.cc:1061] running on GCE node
I20260812 06:20:16.808287  5862 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:16.808326  5862 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:20:16.808341  5862 hybrid_clock.cc:648] HybridClock initialized: now 1786515616808341 us; error 0 us; skew 500 ppm
I20260812 06:20:16.809269  5862 webserver.cc:533] Webserver started at http://127.5.185.129:34471/ using document root <none> and password file <none>
I20260812 06:20:16.809434  5862 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:16.809496  5862 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:16.809567  5862 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:16.809985  5862 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616645234-5862-0/minicluster-data/ts-0-root/instance:
uuid: "154bcbd0ad8b426ebd1dfc26b6b401c7"
format_stamp: "Formatted at 2026-08-12 06:20:16 on dist-test-slave-jpj1"
I20260812 06:20:16.811447  5862 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:16.812487  6028 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:20:16.812769  5862 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:16.812847  5862 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616645234-5862-0/minicluster-data/ts-0-root
uuid: "154bcbd0ad8b426ebd1dfc26b6b401c7"
format_stamp: "Formatted at 2026-08-12 06:20:16 on dist-test-slave-jpj1"
I20260812 06:20:16.812933  5862 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616645234-5862-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616645234-5862-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616645234-5862-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:20:16.825279  5862 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:16.825832  5862 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:16.826402  5862 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:16.827833  5862 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:16.827893  5862 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:16.827947  5862 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:16.827979  5862 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:16.834718  5862 rpc_server.cc:307] RPC server started. Bound to: 127.5.185.129:44201
I20260812 06:20:16.834751  6121 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.5.185.129:44201 every 8 connection(s)
I20260812 06:20:16.847589  6125 heartbeater.cc:344] Connected to a master server at 127.5.185.190:45475
I20260812 06:20:16.847903  6125 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:16.848402  6125 heartbeater.cc:507] Master 127.5.185.190:45475 requested a full tablet report, sending...
I20260812 06:20:16.849822  5911 ts_manager.cc:194] Registered new tserver with Master: 154bcbd0ad8b426ebd1dfc26b6b401c7 (127.5.185.129:44201)
I20260812 06:20:16.849956  5862 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.014618323s
I20260812 06:20:16.851063  5911 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:47768
I20260812 06:20:16.861027  5911 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:47778:
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:20:16.875955  6067 tablet_service.cc:1511] Processing CreateTablet for tablet d566f6635c5a474d9f9773d6bc55264a (DEFAULT_TABLE table=heavy-update-compaction-test [id=6307bf6d5f6344b8bef4e5cc116a89aa]), partition=
I20260812 06:20:16.876389  6067 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet d566f6635c5a474d9f9773d6bc55264a. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:16.878731  6140 tablet_bootstrap.cc:492] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7: Bootstrap starting.
I20260812 06:20:16.879866  6140 tablet_bootstrap.cc:654] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:16.881250  6140 tablet_bootstrap.cc:492] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7: No bootstrap required, opened a new log
I20260812 06:20:16.881345  6140 ts_tablet_manager.cc:1403] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:20:16.881825  6140 raft_consensus.cc:359] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "154bcbd0ad8b426ebd1dfc26b6b401c7" member_type: VOTER last_known_addr { host: "127.5.185.129" port: 44201 } }
I20260812 06:20:16.881928  6140 raft_consensus.cc:385] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:16.881949  6140 raft_consensus.cc:740] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 154bcbd0ad8b426ebd1dfc26b6b401c7, State: Initialized, Role: FOLLOWER
I20260812 06:20:16.882105  6140 consensus_queue.cc:260] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7 [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: "154bcbd0ad8b426ebd1dfc26b6b401c7" member_type: VOTER last_known_addr { host: "127.5.185.129" port: 44201 } }
I20260812 06:20:16.882239  6140 raft_consensus.cc:399] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:16.882287  6140 raft_consensus.cc:493] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:16.882339  6140 raft_consensus.cc:3060] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:16.883190  6140 raft_consensus.cc:515] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "154bcbd0ad8b426ebd1dfc26b6b401c7" member_type: VOTER last_known_addr { host: "127.5.185.129" port: 44201 } }
I20260812 06:20:16.883318  6140 leader_election.cc:304] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7 [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: 154bcbd0ad8b426ebd1dfc26b6b401c7; no voters: 
I20260812 06:20:16.883553  6140 leader_election.cc:290] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:16.883725  6143 raft_consensus.cc:2804] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:16.883955  6140 ts_tablet_manager.cc:1434] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:20:16.884065  6143 raft_consensus.cc:697] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7 [term 1 LEADER]: Becoming Leader. State: Replica: 154bcbd0ad8b426ebd1dfc26b6b401c7, State: Running, Role: LEADER
I20260812 06:20:16.884174  6125 heartbeater.cc:499] Master 127.5.185.190:45475 was elected leader, sending a full tablet report...
I20260812 06:20:16.884269  6143 consensus_queue.cc:237] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7 [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: "154bcbd0ad8b426ebd1dfc26b6b401c7" member_type: VOTER last_known_addr { host: "127.5.185.129" port: 44201 } }
I20260812 06:20:16.887066  5909 catalog_manager.cc:5719] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7 reported cstate change: term changed from 0 to 1, leader changed from <none> to 154bcbd0ad8b426ebd1dfc26b6b401c7 (127.5.185.129). New cstate: current_term: 1 leader_uuid: "154bcbd0ad8b426ebd1dfc26b6b401c7" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "154bcbd0ad8b426ebd1dfc26b6b401c7" member_type: VOTER last_known_addr { host: "127.5.185.129" port: 44201 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:16.956099  5862 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.062s	user 0.023s	sys 0.008s
I20260812 06:20:17.086071  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling FlushMRSOp(d566f6635c5a474d9f9773d6bc55264a): perf score=15.086190
I20260812 06:20:17.240551  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: FlushMRSOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.154s	user 0.118s	sys 0.032s Metrics: {"bytes_written":8615323,"cfile_init":1,"compiler_manager_pool.queue_time_us":457,"delete_count":0,"dirs.queue_time_us":383,"dirs.run_cpu_time_us":174,"dirs.run_wall_time_us":2865,"drs_written":1,"lbm_read_time_us":75,"lbm_reads_lt_1ms":4,"lbm_write_time_us":36500,"lbm_writes_lt_1ms":667,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":289024,"thread_start_us":167,"threads_started":1,"update_count":1050}
I20260812 06:20:17.241775  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling LogGCOp(d566f6635c5a474d9f9773d6bc55264a): free 20743880 bytes of WAL
I20260812 06:20:17.242141  6034 log_reader.cc:385] T d566f6635c5a474d9f9773d6bc55264a: removed 2 log segments from log reader
I20260812 06:20:17.242255  6034 log.cc:1079] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/d566f6635c5a474d9f9773d6bc55264a/wal-000000001 (ops 1-6)
I20260812 06:20:17.242357  6034 log.cc:1079] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/d566f6635c5a474d9f9773d6bc55264a/wal-000000002 (ops 7-11)
I20260812 06:20:17.246691  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: LogGCOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.005s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:20:17.247195  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling UndoDeltaBlockGCOp(d566f6635c5a474d9f9773d6bc55264a): 16411392 bytes on disk
I20260812 06:20:17.248329  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: UndoDeltaBlockGCOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":94,"lbm_reads_lt_1ms":4}
I20260812 06:20:17.249066  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a): perf score=2.188937
I20260812 06:20:17.275959  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.027s	user 0.014s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5470,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:17.276466  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a): perf score=2.188937
I20260812 06:20:17.292088  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.015s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5623,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.292754  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling MajorDeltaCompactionOp(d566f6635c5a474d9f9773d6bc55264a): perf score=1.000000
I20260812 06:20:17.443228  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: MajorDeltaCompactionOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.150s	user 0.099s	sys 0.041s Metrics: {"cfile_cache_miss":433,"cfile_cache_miss_bytes":20672387,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":774,"lbm_read_time_us":9989,"lbm_reads_lt_1ms":469,"lbm_write_time_us":24775,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7296,"thread_start_us":294,"threads_started":5,"update_count":2000}
I20260812 06:20:17.444002  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a): perf score=10.126437
I20260812 06:20:17.496861  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.053s	user 0.025s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18840,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:17.497524  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a): perf score=2.188937
I20260812 06:20:17.513610  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.016s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5778,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.514268  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling MajorDeltaCompactionOp(d566f6635c5a474d9f9773d6bc55264a): perf score=1.000000
I20260812 06:20:17.641538  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: MajorDeltaCompactionOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.127s	user 0.103s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":169,"lbm_read_time_us":10659,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24147,"lbm_writes_lt_1ms":443,"mutex_wait_us":69,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:20:17.642038  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a): perf score=10.126437
I20260812 06:20:17.681985  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.040s	user 0.012s	sys 0.020s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14855,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:17.682475  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a): perf score=2.188937
I20260812 06:20:17.693064  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3747,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.693895  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling MajorDeltaCompactionOp(d566f6635c5a474d9f9773d6bc55264a): perf score=1.000000
I20260812 06:20:17.815254  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: MajorDeltaCompactionOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.121s	user 0.097s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":277,"lbm_read_time_us":8395,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24935,"lbm_writes_lt_1ms":443,"mutex_wait_us":47,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":19968,"update_count":2000}
I20260812 06:20:17.815874  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a): perf score=10.126437
I20260812 06:20:17.864966  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.049s	user 0.015s	sys 0.031s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":16435,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:17.865582  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a): perf score=2.188937
I20260812 06:20:17.881704  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.016s	user 0.001s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6002,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.882212  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling MajorDeltaCompactionOp(d566f6635c5a474d9f9773d6bc55264a): perf score=1.000000
I20260812 06:20:18.022868  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: MajorDeltaCompactionOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.140s	user 0.088s	sys 0.052s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672280,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":615,"lbm_read_time_us":11532,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22321,"lbm_writes_lt_1ms":443,"mutex_wait_us":27,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":20224,"update_count":2000}
I20260812 06:20:18.023415  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a): perf score=10.126437
I20260812 06:20:18.064339  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.041s	user 0.016s	sys 0.017s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14324,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:18.064860  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a): perf score=2.188937
I20260812 06:20:18.075604  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3884,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:18.076327  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling MajorDeltaCompactionOp(d566f6635c5a474d9f9773d6bc55264a): perf score=1.000000
I20260812 06:20:18.197316  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: MajorDeltaCompactionOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.121s	user 0.104s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":834,"lbm_read_time_us":9947,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21577,"lbm_writes_lt_1ms":443,"mutex_wait_us":42,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11008,"update_count":2000}
I20260812 06:20:18.197791  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a): perf score=10.126437
I20260812 06:20:18.240658  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.043s	user 0.022s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14543,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:18.241328  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a): perf score=2.188937
I20260812 06:20:18.252254  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3935,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:18.252897  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling MajorDeltaCompactionOp(d566f6635c5a474d9f9773d6bc55264a): perf score=1.000000
I20260812 06:20:18.370191  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: MajorDeltaCompactionOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.117s	user 0.092s	sys 0.023s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":276,"lbm_read_time_us":8341,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21642,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:20:18.370800  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a): perf score=10.126437
I20260812 06:20:18.418018  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.047s	user 0.024s	sys 0.020s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":16741,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:18.418614  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a): perf score=2.188937
I20260812 06:20:18.429381  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.011s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3947,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:18.429904  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling FlushMRSOp(d566f6635c5a474d9f9773d6bc55264a): perf score=1.000000
I20260812 06:20:18.456809  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: FlushMRSOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.027s	user 0.021s	sys 0.004s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":86,"dirs.run_cpu_time_us":258,"dirs.run_wall_time_us":1699,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1408,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:18.457894  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling UndoDeltaBlockGCOp(d566f6635c5a474d9f9773d6bc55264a): 447 bytes on disk
I20260812 06:20:18.458341  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: UndoDeltaBlockGCOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4}
I20260812 06:20:18.458865  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling MajorDeltaCompactionOp(d566f6635c5a474d9f9773d6bc55264a): perf score=1.000000
I20260812 06:20:18.610966  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: MajorDeltaCompactionOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.152s	user 0.097s	sys 0.052s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":571,"lbm_read_time_us":8411,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27223,"lbm_writes_lt_1ms":443,"mutex_wait_us":56,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":28544,"update_count":2000}
I20260812 06:20:18.611589  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling LogGCOp(d566f6635c5a474d9f9773d6bc55264a): free 112239312 bytes of WAL
I20260812 06:20:18.611840  6034 log_reader.cc:385] T d566f6635c5a474d9f9773d6bc55264a: removed 11 log segments from log reader
I20260812 06:20:18.611898  6034 log.cc:1079] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/d566f6635c5a474d9f9773d6bc55264a/wal-000000003 (ops 12-16)
I20260812 06:20:18.611955  6034 log.cc:1079] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/d566f6635c5a474d9f9773d6bc55264a/wal-000000004 (ops 17-21)
I20260812 06:20:18.611994  6034 log.cc:1079] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/d566f6635c5a474d9f9773d6bc55264a/wal-000000005 (ops 22-26)
I20260812 06:20:18.612030  6034 log.cc:1079] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/d566f6635c5a474d9f9773d6bc55264a/wal-000000006 (ops 27-30)
I20260812 06:20:18.612066  6034 log.cc:1079] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/d566f6635c5a474d9f9773d6bc55264a/wal-000000007 (ops 31-35)
I20260812 06:20:18.612100  6034 log.cc:1079] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/d566f6635c5a474d9f9773d6bc55264a/wal-000000008 (ops 36-40)
I20260812 06:20:18.612134  6034 log.cc:1079] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/d566f6635c5a474d9f9773d6bc55264a/wal-000000009 (ops 41-45)
I20260812 06:20:18.612177  6034 log.cc:1079] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/d566f6635c5a474d9f9773d6bc55264a/wal-000000010 (ops 46-50)
I20260812 06:20:18.612213  6034 log.cc:1079] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/d566f6635c5a474d9f9773d6bc55264a/wal-000000011 (ops 51-55)
I20260812 06:20:18.612247  6034 log.cc:1079] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/d566f6635c5a474d9f9773d6bc55264a/wal-000000012 (ops 56-60)
I20260812 06:20:18.612282  6034 log.cc:1079] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/d566f6635c5a474d9f9773d6bc55264a/wal-000000013 (ops 61-65)
I20260812 06:20:18.640895  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: LogGCOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.029s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:20:18.641367  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a): perf score=14.095187
I20260812 06:20:18.688537  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.047s	user 0.034s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21117,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:18.689177  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a): perf score=2.188937
I20260812 06:20:18.703367  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.014s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4099,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:18.703861  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling MajorDeltaCompactionOp(d566f6635c5a474d9f9773d6bc55264a): perf score=1.000000
I20260812 06:20:18.876755  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: MajorDeltaCompactionOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.173s	user 0.098s	sys 0.063s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":261,"lbm_read_time_us":11400,"lbm_reads_lt_1ms":564,"lbm_write_time_us":25928,"lbm_writes_lt_1ms":543,"mutex_wait_us":63,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:18.877282  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a): perf score=14.095187
I20260812 06:20:18.927738  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.050s	user 0.022s	sys 0.027s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21805,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:18.928200  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a): perf score=2.188937
I20260812 06:20:18.939427  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3893,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:18.939955  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling MajorDeltaCompactionOp(d566f6635c5a474d9f9773d6bc55264a): perf score=1.000000
I20260812 06:20:19.093191  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: MajorDeltaCompactionOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.153s	user 0.116s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":130,"lbm_read_time_us":9514,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31188,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:19.094025  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a): perf score=11.118625
I20260812 06:20:19.123351  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.029s	user 0.023s	sys 0.003s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":12261,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:19.123898  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a): perf score=2.188937
I20260812 06:20:19.138201  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.014s	user 0.012s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4689,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:19.138775  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling MajorDeltaCompactionOp(d566f6635c5a474d9f9773d6bc55264a): perf score=1.000000
I20260812 06:20:19.262604  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: MajorDeltaCompactionOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.124s	user 0.104s	sys 0.019s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672267,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":737,"lbm_read_time_us":9575,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23719,"lbm_writes_lt_1ms":443,"mutex_wait_us":348,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3456,"update_count":2000}
I20260812 06:20:19.263427  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a): perf score=10.126437
I20260812 06:20:19.305943  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.042s	user 0.019s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16312,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:19.306545  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a): perf score=2.188937
I20260812 06:20:19.317375  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3832,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:19.317903  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling MajorDeltaCompactionOp(d566f6635c5a474d9f9773d6bc55264a): perf score=1.000000
I20260812 06:20:19.445286  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: MajorDeltaCompactionOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.127s	user 0.103s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":219,"lbm_read_time_us":8378,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24548,"lbm_writes_lt_1ms":443,"mutex_wait_us":63,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12800,"update_count":2000}
I20260812 06:20:19.446175  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a): perf score=10.126437
I20260812 06:20:19.492910  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.047s	user 0.026s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15529,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:19.493484  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a): perf score=2.188937
I20260812 06:20:19.504141  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3878,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:19.504637  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling MajorDeltaCompactionOp(d566f6635c5a474d9f9773d6bc55264a): perf score=1.000000
I20260812 06:20:19.649614  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: MajorDeltaCompactionOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.145s	user 0.103s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":206,"lbm_read_time_us":10926,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23409,"lbm_writes_lt_1ms":443,"mutex_wait_us":23,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":82176,"update_count":2000}
I20260812 06:20:19.650135  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a): perf score=10.126437
I20260812 06:20:19.696362  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.046s	user 0.031s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17291,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:19.696909  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a): perf score=2.188937
I20260812 06:20:19.707844  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3734,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:19.708315  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling MajorDeltaCompactionOp(d566f6635c5a474d9f9773d6bc55264a): perf score=1.000000
I20260812 06:20:19.837564  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: MajorDeltaCompactionOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.129s	user 0.108s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":458,"lbm_read_time_us":9274,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24337,"lbm_writes_lt_1ms":443,"mutex_wait_us":277,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10112,"update_count":2000}
I20260812 06:20:19.838204  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a): perf score=10.126437
I20260812 06:20:19.870862  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.032s	user 0.020s	sys 0.007s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13049,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:19.871340  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a): perf score=2.188937
I20260812 06:20:19.882689  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4179,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:19.883356  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling FlushMRSOp(d566f6635c5a474d9f9773d6bc55264a): perf score=1.000000
I20260812 06:20:19.912555  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: FlushMRSOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.029s	user 0.024s	sys 0.001s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":56,"dirs.run_cpu_time_us":239,"dirs.run_wall_time_us":1377,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1347,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:19.913373  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling LogGCOp(d566f6635c5a474d9f9773d6bc55264a): free 121006437 bytes of WAL
I20260812 06:20:19.913614  6034 log_reader.cc:385] T d566f6635c5a474d9f9773d6bc55264a: removed 12 log segments from log reader
I20260812 06:20:19.913676  6034 log.cc:1079] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/d566f6635c5a474d9f9773d6bc55264a/wal-000000014 (ops 66-70)
I20260812 06:20:19.913719  6034 log.cc:1079] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/d566f6635c5a474d9f9773d6bc55264a/wal-000000015 (ops 71-75)
I20260812 06:20:19.913754  6034 log.cc:1079] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/d566f6635c5a474d9f9773d6bc55264a/wal-000000016 (ops 76-80)
I20260812 06:20:19.913779  6034 log.cc:1079] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/d566f6635c5a474d9f9773d6bc55264a/wal-000000017 (ops 81-85)
I20260812 06:20:19.913801  6034 log.cc:1079] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/d566f6635c5a474d9f9773d6bc55264a/wal-000000018 (ops 86-90)
I20260812 06:20:19.913830  6034 log.cc:1079] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/d566f6635c5a474d9f9773d6bc55264a/wal-000000019 (ops 91-95)
I20260812 06:20:19.913857  6034 log.cc:1079] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/d566f6635c5a474d9f9773d6bc55264a/wal-000000020 (ops 96-100)
I20260812 06:20:19.913887  6034 log.cc:1079] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/d566f6635c5a474d9f9773d6bc55264a/wal-000000021 (ops 101-105)
I20260812 06:20:19.913920  6034 log.cc:1079] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/d566f6635c5a474d9f9773d6bc55264a/wal-000000022 (ops 106-110)
I20260812 06:20:19.913950  6034 log.cc:1079] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/d566f6635c5a474d9f9773d6bc55264a/wal-000000023 (ops 111-114)
I20260812 06:20:19.913978  6034 log.cc:1079] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/d566f6635c5a474d9f9773d6bc55264a/wal-000000024 (ops 115-119)
I20260812 06:20:19.914004  6034 log.cc:1079] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/d566f6635c5a474d9f9773d6bc55264a/wal-000000025 (ops 120-124)
I20260812 06:20:19.942894  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: LogGCOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.029s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:20:19.943382  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling UndoDeltaBlockGCOp(d566f6635c5a474d9f9773d6bc55264a): 472 bytes on disk
I20260812 06:20:19.943905  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: UndoDeltaBlockGCOp(d566f6635c5a474d9f9773d6bc55264a) 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:20:19.944530  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a): perf score=3.181125
I20260812 06:20:19.957077  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.012s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4392,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:19.957494  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling LogGCOp(d566f6635c5a474d9f9773d6bc55264a): free 11564877 bytes of WAL
I20260812 06:20:19.957710  6034 log_reader.cc:385] T d566f6635c5a474d9f9773d6bc55264a: removed 1 log segments from log reader
I20260812 06:20:19.957757  6034 log.cc:1079] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/d566f6635c5a474d9f9773d6bc55264a/wal-000000026 (ops 125-128)
I20260812 06:20:19.959990  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: LogGCOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.002s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:20:19.960319  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a): perf score=2.188937
I20260812 06:20:19.970757  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.010s	user 0.007s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3364,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:19.971486  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling MajorDeltaCompactionOp(d566f6635c5a474d9f9773d6bc55264a): perf score=1.000000
I20260812 06:20:20.138576  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: MajorDeltaCompactionOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.167s	user 0.101s	sys 0.061s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877327,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":299,"lbm_read_time_us":11878,"lbm_reads_lt_1ms":674,"lbm_write_time_us":32385,"lbm_writes_lt_1ms":643,"mutex_wait_us":67,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":11904,"thread_start_us":77,"threads_started":1,"update_count":3000}
I20260812 06:20:20.139166  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a): perf score=14.095187
I20260812 06:20:20.194934  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.056s	user 0.036s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":27221,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":400,"reinsert_count":0,"update_count":2000}
I20260812 06:20:20.195477  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a): perf score=2.188937
I20260812 06:20:20.208181  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.013s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4539,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.208747  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling MajorDeltaCompactionOp(d566f6635c5a474d9f9773d6bc55264a): perf score=1.000000
I20260812 06:20:20.370404  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: MajorDeltaCompactionOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.161s	user 0.122s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1145,"lbm_read_time_us":9723,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30433,"lbm_writes_lt_1ms":543,"mutex_wait_us":369,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":2500}
I20260812 06:20:20.370987  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a): perf score=14.095187
I20260812 06:20:20.422977  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.052s	user 0.038s	sys 0.004s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20582,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:20.423821  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling MajorDeltaCompactionOp(d566f6635c5a474d9f9773d6bc55264a): perf score=1.000000
I20260812 06:20:20.574378  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: MajorDeltaCompactionOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.147s	user 0.084s	sys 0.056s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":415,"lbm_read_time_us":10136,"lbm_reads_lt_1ms":463,"lbm_write_time_us":23474,"lbm_writes_lt_1ms":443,"mutex_wait_us":46,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5120,"update_count":2000}
I20260812 06:20:20.575006  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a): perf score=11.118625
I20260812 06:20:20.612051  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.037s	user 0.029s	sys 0.007s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15626,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:20.612644  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a): perf score=2.188937
I20260812 06:20:20.637274  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.024s	user 0.010s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4501,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:20.637876  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a): perf score=2.188937
I20260812 06:20:20.648298  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3851,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.648782  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling MajorDeltaCompactionOp(d566f6635c5a474d9f9773d6bc55264a): perf score=1.000000
I20260812 06:20:20.821301  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: MajorDeltaCompactionOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.172s	user 0.111s	sys 0.053s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":747,"lbm_read_time_us":10953,"lbm_reads_lt_1ms":573,"lbm_write_time_us":27442,"lbm_writes_lt_1ms":543,"mutex_wait_us":290,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:20.821833  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a): perf score=11.118625
I20260812 06:20:20.851046  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.029s	user 0.012s	sys 0.013s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":12034,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:20.852042  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a): perf score=2.188937
I20260812 06:20:20.866562  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.014s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3850,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:20.867157  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling MajorDeltaCompactionOp(d566f6635c5a474d9f9773d6bc55264a): perf score=1.000000
I20260812 06:20:20.989984  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: MajorDeltaCompactionOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.123s	user 0.098s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":594,"lbm_read_time_us":7319,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23552,"lbm_writes_lt_1ms":443,"mutex_wait_us":324,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":48512,"update_count":2000}
I20260812 06:20:20.990505  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a): perf score=11.118625
I20260812 06:20:21.023280  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.033s	user 0.025s	sys 0.004s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13524,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:21.024340  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a): perf score=2.188937
I20260812 06:20:21.045495  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.021s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3834,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:21.046016  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a): perf score=2.188937
I20260812 06:20:21.056728  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.011s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3792,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.057247  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling MajorDeltaCompactionOp(d566f6635c5a474d9f9773d6bc55264a): perf score=1.000000
I20260812 06:20:21.216346  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: MajorDeltaCompactionOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.159s	user 0.128s	sys 0.021s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":963,"lbm_read_time_us":11166,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29877,"lbm_writes_lt_1ms":543,"mutex_wait_us":31,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10112,"update_count":2500}
I20260812 06:20:21.216902  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a): perf score=14.095187
I20260812 06:20:21.269012  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.052s	user 0.019s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19726,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:21.269659  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a): perf score=2.188937
I20260812 06:20:21.280493  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3730,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.281018  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling FlushMRSOp(d566f6635c5a474d9f9773d6bc55264a): perf score=1.000000
I20260812 06:20:21.313374  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: FlushMRSOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.032s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1234475,"cfile_init":1,"dirs.queue_time_us":72,"dirs.run_cpu_time_us":218,"dirs.run_wall_time_us":1414,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1626,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:21.314107  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling LogGCOp(d566f6635c5a474d9f9773d6bc55264a): free 121006640 bytes of WAL
I20260812 06:20:21.314337  6034 log_reader.cc:385] T d566f6635c5a474d9f9773d6bc55264a: removed 12 log segments from log reader
I20260812 06:20:21.314383  6034 log.cc:1079] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/d566f6635c5a474d9f9773d6bc55264a/wal-000000027 (ops 129-133)
I20260812 06:20:21.314410  6034 log.cc:1079] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/d566f6635c5a474d9f9773d6bc55264a/wal-000000028 (ops 134-138)
I20260812 06:20:21.314440  6034 log.cc:1079] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/d566f6635c5a474d9f9773d6bc55264a/wal-000000029 (ops 139-142)
I20260812 06:20:21.314472  6034 log.cc:1079] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/d566f6635c5a474d9f9773d6bc55264a/wal-000000030 (ops 143-147)
I20260812 06:20:21.314507  6034 log.cc:1079] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/d566f6635c5a474d9f9773d6bc55264a/wal-000000031 (ops 148-152)
I20260812 06:20:21.314539  6034 log.cc:1079] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/d566f6635c5a474d9f9773d6bc55264a/wal-000000032 (ops 153-157)
I20260812 06:20:21.314572  6034 log.cc:1079] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/d566f6635c5a474d9f9773d6bc55264a/wal-000000033 (ops 158-162)
I20260812 06:20:21.314604  6034 log.cc:1079] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/d566f6635c5a474d9f9773d6bc55264a/wal-000000034 (ops 163-167)
I20260812 06:20:21.314636  6034 log.cc:1079] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/d566f6635c5a474d9f9773d6bc55264a/wal-000000035 (ops 168-172)
I20260812 06:20:21.314677  6034 log.cc:1079] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/d566f6635c5a474d9f9773d6bc55264a/wal-000000036 (ops 173-177)
I20260812 06:20:21.314710  6034 log.cc:1079] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/d566f6635c5a474d9f9773d6bc55264a/wal-000000037 (ops 178-182)
I20260812 06:20:21.314741  6034 log.cc:1079] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/d566f6635c5a474d9f9773d6bc55264a/wal-000000038 (ops 183-187)
I20260812 06:20:21.337697  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: LogGCOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.023s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:20:21.338121  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a): perf score=3.181125
I20260812 06:20:21.349880  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4167,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:21.350342  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling UndoDeltaBlockGCOp(d566f6635c5a474d9f9773d6bc55264a): 472 bytes on disk
I20260812 06:20:21.350800  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: UndoDeltaBlockGCOp(d566f6635c5a474d9f9773d6bc55264a) 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:20:21.351352  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a): perf score=2.188937
I20260812 06:20:21.363823  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.012s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4762,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:21.364374  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling MajorDeltaCompactionOp(d566f6635c5a474d9f9773d6bc55264a): perf score=1.000000
I20260812 06:20:21.547216  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: MajorDeltaCompactionOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.183s	user 0.131s	sys 0.052s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979738,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":880,"lbm_read_time_us":13036,"lbm_reads_lt_1ms":774,"lbm_write_time_us":36933,"lbm_writes_lt_1ms":743,"mutex_wait_us":268,"peak_mem_usage":87969044,"reinsert_count":0,"thread_start_us":76,"threads_started":1,"update_count":3500}
I20260812 06:20:21.547859  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a): perf score=14.095187
I20260812 06:20:21.598905  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.051s	user 0.038s	sys 0.009s Metrics: {"bytes_written":16409908,"delete_count":0,"lbm_write_time_us":22570,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:21.599406  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a): perf score=2.188937
I20260812 06:20:21.609499  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: FlushDeltaMemStoresOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3660,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.610013  6126 maintenance_manager.cc:419] P 154bcbd0ad8b426ebd1dfc26b6b401c7: Scheduling MajorDeltaCompactionOp(d566f6635c5a474d9f9773d6bc55264a): perf score=1.000000
I20260812 06:20:21.646108  5862 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.690s	user 1.693s	sys 0.117s
I20260812 06:20:21.699350  5862 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.053s	user 0.002s	sys 0.000s
I20260812 06:20:21.700109  5862 tablet_server.cc:179] TabletServer@127.5.185.129:0 shutting down...
I20260812 06:20:21.742856  6034 maintenance_manager.cc:643] P 154bcbd0ad8b426ebd1dfc26b6b401c7: MajorDeltaCompactionOp(d566f6635c5a474d9f9773d6bc55264a) complete. Timing: real 0.133s	user 0.099s	sys 0.031s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774695,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":907,"lbm_read_time_us":11819,"lbm_reads_lt_1ms":568,"lbm_write_time_us":25379,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":542,"mutex_wait_us":31,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":20864,"update_count":2500}
I20260812 06:20:21.743620  5862 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:21.744059  5862 tablet_replica.cc:333] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7: stopping tablet replica
I20260812 06:20:21.744290  5862 raft_consensus.cc:2243] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:21.754683  5862 raft_consensus.cc:2272] T d566f6635c5a474d9f9773d6bc55264a P 154bcbd0ad8b426ebd1dfc26b6b401c7 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:21.771827  5862 tablet_server.cc:196] TabletServer@127.5.185.129:0 shutdown complete.
I20260812 06:20:21.788771  5862 master.cc:562] Master@127.5.185.190:45475 shutting down...
I20260812 06:20:21.792348  5862 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 9a071e225c1d44b887324d77196e9833 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:21.792541  5862 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 9a071e225c1d44b887324d77196e9833 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:21.792668  5862 tablet_replica.cc:333] T 00000000000000000000000000000000 P 9a071e225c1d44b887324d77196e9833: stopping tablet replica
I20260812 06:20:21.804999  5862 master.cc:584] Master@127.5.185.190:45475 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5229 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:20:21.885296  5862 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.5.185.190:44331
I20260812 06:20:21.885706  5862 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:21.887595  6183 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:21.887735  6181 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:20:21.887841  6180 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:20:21.888041  5862 server_base.cc:1061] running on GCE node
I20260812 06:20:21.888206  5862 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:21.888247  5862 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:20:21.888298  5862 hybrid_clock.cc:648] HybridClock initialized: now 1786515621888298 us; error 0 us; skew 500 ppm
I20260812 06:20:21.889086  5862 webserver.cc:533] Webserver started at http://127.5.185.190:34345/ using document root <none> and password file <none>
I20260812 06:20:21.889250  5862 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:21.889313  5862 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:21.889391  5862 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:21.889770  5862 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616645234-5862-0/minicluster-data/master-0-root/instance:
uuid: "83470e201556479cb4d52573a8a3d08e"
format_stamp: "Formatted at 2026-08-12 06:20:21 on dist-test-slave-jpj1"
I20260812 06:20:21.891242  5862 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:21.892259  6190 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:20:21.892483  5862 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:21.892554  5862 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616645234-5862-0/minicluster-data/master-0-root
uuid: "83470e201556479cb4d52573a8a3d08e"
format_stamp: "Formatted at 2026-08-12 06:20:21 on dist-test-slave-jpj1"
I20260812 06:20:21.892627  5862 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616645234-5862-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616645234-5862-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616645234-5862-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:20:21.917822  5862 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:21.918283  5862 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:21.922540  5862 rpc_server.cc:307] RPC server started. Bound to: 127.5.185.190:44331
I20260812 06:20:21.928941  6282 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.5.185.190:44331 every 8 connection(s)
I20260812 06:20:21.929466  6284 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:20:21.931659  6284 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 83470e201556479cb4d52573a8a3d08e: Bootstrap starting.
I20260812 06:20:21.932541  6284 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 83470e201556479cb4d52573a8a3d08e: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:21.933634  6284 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 83470e201556479cb4d52573a8a3d08e: No bootstrap required, opened a new log
I20260812 06:20:21.934077  6284 raft_consensus.cc:359] T 00000000000000000000000000000000 P 83470e201556479cb4d52573a8a3d08e [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "83470e201556479cb4d52573a8a3d08e" member_type: VOTER }
I20260812 06:20:21.934173  6284 raft_consensus.cc:385] T 00000000000000000000000000000000 P 83470e201556479cb4d52573a8a3d08e [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:21.934195  6284 raft_consensus.cc:740] T 00000000000000000000000000000000 P 83470e201556479cb4d52573a8a3d08e [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 83470e201556479cb4d52573a8a3d08e, State: Initialized, Role: FOLLOWER
I20260812 06:20:21.934346  6284 consensus_queue.cc:260] T 00000000000000000000000000000000 P 83470e201556479cb4d52573a8a3d08e [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: "83470e201556479cb4d52573a8a3d08e" member_type: VOTER }
I20260812 06:20:21.934419  6284 raft_consensus.cc:399] T 00000000000000000000000000000000 P 83470e201556479cb4d52573a8a3d08e [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:21.934453  6284 raft_consensus.cc:493] T 00000000000000000000000000000000 P 83470e201556479cb4d52573a8a3d08e [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:21.934504  6284 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 83470e201556479cb4d52573a8a3d08e [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:21.935211  6284 raft_consensus.cc:515] T 00000000000000000000000000000000 P 83470e201556479cb4d52573a8a3d08e [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "83470e201556479cb4d52573a8a3d08e" member_type: VOTER }
I20260812 06:20:21.935348  6284 leader_election.cc:304] T 00000000000000000000000000000000 P 83470e201556479cb4d52573a8a3d08e [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: 83470e201556479cb4d52573a8a3d08e; no voters: 
I20260812 06:20:21.935575  6284 leader_election.cc:290] T 00000000000000000000000000000000 P 83470e201556479cb4d52573a8a3d08e [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:21.935703  6299 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 83470e201556479cb4d52573a8a3d08e [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:21.935928  6299 raft_consensus.cc:697] T 00000000000000000000000000000000 P 83470e201556479cb4d52573a8a3d08e [term 1 LEADER]: Becoming Leader. State: Replica: 83470e201556479cb4d52573a8a3d08e, State: Running, Role: LEADER
I20260812 06:20:21.936084  6284 sys_catalog.cc:565] T 00000000000000000000000000000000 P 83470e201556479cb4d52573a8a3d08e [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:21.936075  6299 consensus_queue.cc:237] T 00000000000000000000000000000000 P 83470e201556479cb4d52573a8a3d08e [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: "83470e201556479cb4d52573a8a3d08e" member_type: VOTER }
I20260812 06:20:21.936559  6308 sys_catalog.cc:455] T 00000000000000000000000000000000 P 83470e201556479cb4d52573a8a3d08e [sys.catalog]: SysCatalogTable state changed. Reason: New leader 83470e201556479cb4d52573a8a3d08e. Latest consensus state: current_term: 1 leader_uuid: "83470e201556479cb4d52573a8a3d08e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "83470e201556479cb4d52573a8a3d08e" member_type: VOTER } }
I20260812 06:20:21.936545  6302 sys_catalog.cc:455] T 00000000000000000000000000000000 P 83470e201556479cb4d52573a8a3d08e [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "83470e201556479cb4d52573a8a3d08e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "83470e201556479cb4d52573a8a3d08e" member_type: VOTER } }
I20260812 06:20:21.936659  6308 sys_catalog.cc:458] T 00000000000000000000000000000000 P 83470e201556479cb4d52573a8a3d08e [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:21.936671  6302 sys_catalog.cc:458] T 00000000000000000000000000000000 P 83470e201556479cb4d52573a8a3d08e [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:21.936964  6316 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:21.937789  6316 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:21.938071  5862 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:21.939741  6316 catalog_manager.cc:1383] Generated new cluster ID: 70dfe0bd92e0431b8bd25e4c23d9643d
I20260812 06:20:21.939802  6316 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:21.948074  6316 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:21.948619  6316 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:21.953444  6316 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 83470e201556479cb4d52573a8a3d08e: Generated new TSK 0
I20260812 06:20:21.953596  6316 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:21.970643  5862 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:21.972704  6339 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:20:21.972877  5862 server_base.cc:1061] running on GCE node
W20260812 06:20:21.972879  6344 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:21.973064  6341 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:20:21.973294  5862 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:21.973340  5862 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:20:21.973354  5862 hybrid_clock.cc:648] HybridClock initialized: now 1786515621973355 us; error 0 us; skew 500 ppm
I20260812 06:20:21.974272  5862 webserver.cc:533] Webserver started at http://127.5.185.129:44143/ using document root <none> and password file <none>
I20260812 06:20:21.974431  5862 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:21.974475  5862 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:21.974530  5862 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:21.974900  5862 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616645234-5862-0/minicluster-data/ts-0-root/instance:
uuid: "8c9f8ddc558d444890bcf4dfddee61dd"
format_stamp: "Formatted at 2026-08-12 06:20:21 on dist-test-slave-jpj1"
I20260812 06:20:21.976506  5862 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:20:21.977447  6352 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:20:21.977725  5862 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:21.977805  5862 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616645234-5862-0/minicluster-data/ts-0-root
uuid: "8c9f8ddc558d444890bcf4dfddee61dd"
format_stamp: "Formatted at 2026-08-12 06:20:21 on dist-test-slave-jpj1"
I20260812 06:20:21.977878  5862 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616645234-5862-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616645234-5862-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616645234-5862-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:20:21.990650  5862 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:21.991036  5862 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:21.991346  5862 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:21.991864  5862 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:21.991904  5862 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:21.991951  5862 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:21.991979  5862 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:21.996333  5862 rpc_server.cc:307] RPC server started. Bound to: 127.5.185.129:38819
I20260812 06:20:21.998023  6476 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.5.185.129:38819 every 8 connection(s)
I20260812 06:20:22.005681  6477 heartbeater.cc:344] Connected to a master server at 127.5.185.190:44331
I20260812 06:20:22.005831  6477 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:22.006080  6477 heartbeater.cc:507] Master 127.5.185.190:44331 requested a full tablet report, sending...
I20260812 06:20:22.006718  6221 ts_manager.cc:194] Registered new tserver with Master: 8c9f8ddc558d444890bcf4dfddee61dd (127.5.185.129:38819)
I20260812 06:20:22.007028  5862 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.010016948s
I20260812 06:20:22.007527  6221 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:45678
I20260812 06:20:22.014662  6221 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:45682:
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:20:22.023941  6410 tablet_service.cc:1511] Processing CreateTablet for tablet 181722e80dc14a17802fe6f6068092d8 (DEFAULT_TABLE table=heavy-update-compaction-test [id=8705d4ffd020401cb31a70f6a9b33e8d]), partition=
I20260812 06:20:22.024243  6410 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 181722e80dc14a17802fe6f6068092d8. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:22.026479  6508 tablet_bootstrap.cc:492] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd: Bootstrap starting.
I20260812 06:20:22.027412  6508 tablet_bootstrap.cc:654] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:22.028589  6508 tablet_bootstrap.cc:492] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd: No bootstrap required, opened a new log
I20260812 06:20:22.028689  6508 ts_tablet_manager.cc:1403] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:22.029131  6508 raft_consensus.cc:359] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8c9f8ddc558d444890bcf4dfddee61dd" member_type: VOTER last_known_addr { host: "127.5.185.129" port: 38819 } }
I20260812 06:20:22.029244  6508 raft_consensus.cc:385] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:22.029296  6508 raft_consensus.cc:740] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 8c9f8ddc558d444890bcf4dfddee61dd, State: Initialized, Role: FOLLOWER
I20260812 06:20:22.029633  6508 consensus_queue.cc:260] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd [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: "8c9f8ddc558d444890bcf4dfddee61dd" member_type: VOTER last_known_addr { host: "127.5.185.129" port: 38819 } }
I20260812 06:20:22.029742  6508 raft_consensus.cc:399] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:22.029784  6508 raft_consensus.cc:493] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:22.029835  6508 raft_consensus.cc:3060] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:22.030718  6508 raft_consensus.cc:515] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8c9f8ddc558d444890bcf4dfddee61dd" member_type: VOTER last_known_addr { host: "127.5.185.129" port: 38819 } }
I20260812 06:20:22.030874  6508 leader_election.cc:304] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd [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: 8c9f8ddc558d444890bcf4dfddee61dd; no voters: 
I20260812 06:20:22.031086  6508 leader_election.cc:290] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:22.031271  6510 raft_consensus.cc:2804] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:22.031456  6508 ts_tablet_manager.cc:1434] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:20:22.031479  6510 raft_consensus.cc:697] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd [term 1 LEADER]: Becoming Leader. State: Replica: 8c9f8ddc558d444890bcf4dfddee61dd, State: Running, Role: LEADER
I20260812 06:20:22.031574  6477 heartbeater.cc:499] Master 127.5.185.190:44331 was elected leader, sending a full tablet report...
I20260812 06:20:22.031663  6510 consensus_queue.cc:237] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd [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: "8c9f8ddc558d444890bcf4dfddee61dd" member_type: VOTER last_known_addr { host: "127.5.185.129" port: 38819 } }
I20260812 06:20:22.033082  6221 catalog_manager.cc:5719] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd reported cstate change: term changed from 0 to 1, leader changed from <none> to 8c9f8ddc558d444890bcf4dfddee61dd (127.5.185.129). New cstate: current_term: 1 leader_uuid: "8c9f8ddc558d444890bcf4dfddee61dd" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8c9f8ddc558d444890bcf4dfddee61dd" member_type: VOTER last_known_addr { host: "127.5.185.129" port: 38819 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:22.092959  5862 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.053s	user 0.013s	sys 0.010s
I20260812 06:20:22.248497  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling FlushMRSOp(181722e80dc14a17802fe6f6068092d8): perf score=19.054940
I20260812 06:20:22.399499  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: FlushMRSOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.151s	user 0.111s	sys 0.036s Metrics: {"bytes_written":12676712,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":64,"dirs.run_cpu_time_us":232,"dirs.run_wall_time_us":963,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":38911,"lbm_writes_lt_1ms":776,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"spinlock_wait_cycles":768,"update_count":1545}
I20260812 06:20:22.400216  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling LogGCOp(181722e80dc14a17802fe6f6068092d8): free 20743880 bytes of WAL
I20260812 06:20:22.400445  6365 log_reader.cc:385] T 181722e80dc14a17802fe6f6068092d8: removed 2 log segments from log reader
I20260812 06:20:22.400489  6365 log.cc:1079] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/181722e80dc14a17802fe6f6068092d8/wal-000000001 (ops 1-6)
I20260812 06:20:22.400530  6365 log.cc:1079] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/181722e80dc14a17802fe6f6068092d8/wal-000000002 (ops 7-11)
I20260812 06:20:22.404827  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: LogGCOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.004s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:20:22.405181  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8): perf score=2.188937
I20260812 06:20:22.430524  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.025s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3323180,"delete_count":0,"lbm_write_time_us":4154,"lbm_writes_lt_1ms":84,"reinsert_count":0,"update_count":405}
I20260812 06:20:22.430967  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling UndoDeltaBlockGCOp(181722e80dc14a17802fe6f6068092d8): 16821650 bytes on disk
I20260812 06:20:22.431371  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: UndoDeltaBlockGCOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4}
I20260812 06:20:22.431804  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8): perf score=2.188937
I20260812 06:20:22.443265  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4469,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.443753  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling MajorDeltaCompactionOp(181722e80dc14a17802fe6f6068092d8): perf score=1.000000
I20260812 06:20:22.602720  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: MajorDeltaCompactionOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.159s	user 0.109s	sys 0.049s Metrics: {"cfile_cache_miss":523,"cfile_cache_miss_bytes":24405546,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":539,"lbm_read_time_us":14129,"lbm_reads_lt_1ms":559,"lbm_write_time_us":25096,"lbm_writes_lt_1ms":533,"peak_mem_usage":61665166,"reinsert_count":0,"spinlock_wait_cycles":10624,"thread_start_us":288,"threads_started":5,"update_count":2450}
I20260812 06:20:22.603189  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8): perf score=14.095187
I20260812 06:20:22.652321  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.049s	user 0.026s	sys 0.016s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":18605,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:22.652905  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8): perf score=2.188937
I20260812 06:20:22.663949  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3740,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.664425  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling MajorDeltaCompactionOp(181722e80dc14a17802fe6f6068092d8): perf score=1.000000
I20260812 06:20:22.834043  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: MajorDeltaCompactionOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.169s	user 0.114s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1259,"lbm_read_time_us":10601,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30603,"lbm_writes_lt_1ms":543,"mutex_wait_us":408,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7808,"update_count":2500}
I20260812 06:20:22.834622  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8): perf score=14.095187
I20260812 06:20:22.884356  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.050s	user 0.027s	sys 0.020s Metrics: {"bytes_written":16409906,"delete_count":0,"lbm_write_time_us":21645,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:22.884826  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling MajorDeltaCompactionOp(181722e80dc14a17802fe6f6068092d8): perf score=1.000000
I20260812 06:20:23.037472  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: MajorDeltaCompactionOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.152s	user 0.087s	sys 0.056s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713157,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":131,"lbm_read_time_us":10315,"lbm_reads_lt_1ms":463,"lbm_write_time_us":23269,"lbm_writes_lt_1ms":443,"mutex_wait_us":49,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4224,"update_count":2000}
I20260812 06:20:23.038002  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8): perf score=14.095187
I20260812 06:20:23.084529  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.046s	user 0.028s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18013,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:23.085063  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8): perf score=2.188937
I20260812 06:20:23.096895  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4129,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.097379  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling MajorDeltaCompactionOp(181722e80dc14a17802fe6f6068092d8): perf score=1.000000
I20260812 06:20:23.288426  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: MajorDeltaCompactionOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.191s	user 0.128s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":839,"lbm_read_time_us":11480,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28692,"lbm_writes_lt_1ms":543,"mutex_wait_us":27,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":24192,"update_count":2500}
I20260812 06:20:23.288932  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8): perf score=14.095187
I20260812 06:20:23.338891  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.050s	user 0.029s	sys 0.015s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":20414,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:23.339490  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8): perf score=2.188937
I20260812 06:20:23.350577  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.011s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3856,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.351047  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling MajorDeltaCompactionOp(181722e80dc14a17802fe6f6068092d8): perf score=1.000000
I20260812 06:20:23.502611  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: MajorDeltaCompactionOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.151s	user 0.123s	sys 0.026s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":814,"lbm_read_time_us":12102,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28504,"lbm_writes_lt_1ms":543,"mutex_wait_us":33,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10752,"update_count":2500}
I20260812 06:20:23.503172  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8): perf score=11.118625
I20260812 06:20:23.538753  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.035s	user 0.019s	sys 0.013s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":14953,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:23.539254  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8): perf score=2.188937
I20260812 06:20:23.564327  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.025s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4498,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:23.564968  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8): perf score=2.188937
I20260812 06:20:23.575358  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3700,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.575948  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling FlushMRSOp(181722e80dc14a17802fe6f6068092d8): perf score=1.000000
I20260812 06:20:23.609155  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: FlushMRSOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.033s	user 0.030s	sys 0.002s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":59,"dirs.run_cpu_time_us":241,"dirs.run_wall_time_us":1370,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2119,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:23.609877  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling LogGCOp(181722e80dc14a17802fe6f6068092d8): free 120553321 bytes of WAL
I20260812 06:20:23.610172  6365 log_reader.cc:385] T 181722e80dc14a17802fe6f6068092d8: removed 12 log segments from log reader
I20260812 06:20:23.610231  6365 log.cc:1079] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/181722e80dc14a17802fe6f6068092d8/wal-000000003 (ops 12-16)
I20260812 06:20:23.610272  6365 log.cc:1079] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/181722e80dc14a17802fe6f6068092d8/wal-000000004 (ops 17-20)
I20260812 06:20:23.610303  6365 log.cc:1079] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/181722e80dc14a17802fe6f6068092d8/wal-000000005 (ops 21-25)
I20260812 06:20:23.610339  6365 log.cc:1079] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/181722e80dc14a17802fe6f6068092d8/wal-000000006 (ops 26-30)
I20260812 06:20:23.610369  6365 log.cc:1079] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/181722e80dc14a17802fe6f6068092d8/wal-000000007 (ops 31-35)
I20260812 06:20:23.610399  6365 log.cc:1079] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/181722e80dc14a17802fe6f6068092d8/wal-000000008 (ops 36-40)
I20260812 06:20:23.610430  6365 log.cc:1079] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/181722e80dc14a17802fe6f6068092d8/wal-000000009 (ops 41-45)
I20260812 06:20:23.610458  6365 log.cc:1079] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/181722e80dc14a17802fe6f6068092d8/wal-000000010 (ops 46-50)
I20260812 06:20:23.610488  6365 log.cc:1079] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/181722e80dc14a17802fe6f6068092d8/wal-000000011 (ops 51-55)
I20260812 06:20:23.610518  6365 log.cc:1079] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/181722e80dc14a17802fe6f6068092d8/wal-000000012 (ops 56-60)
I20260812 06:20:23.610548  6365 log.cc:1079] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/181722e80dc14a17802fe6f6068092d8/wal-000000013 (ops 61-64)
I20260812 06:20:23.610577  6365 log.cc:1079] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/181722e80dc14a17802fe6f6068092d8/wal-000000014 (ops 65-69)
I20260812 06:20:23.635963  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: LogGCOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.026s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:20:23.636391  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8): perf score=3.181125
I20260812 06:20:23.659873  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.023s	user 0.008s	sys 0.014s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4295,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:23.660421  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8): perf score=2.188937
I20260812 06:20:23.675040  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.014s	user 0.004s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5341,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:23.675624  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling MajorDeltaCompactionOp(181722e80dc14a17802fe6f6068092d8): perf score=1.000000
I20260812 06:20:23.898116  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: MajorDeltaCompactionOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.222s	user 0.153s	sys 0.069s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":33020844,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":49,"lbm_read_time_us":17669,"lbm_reads_lt_1ms":775,"lbm_write_time_us":33874,"lbm_writes_lt_1ms":743,"mutex_wait_us":28,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":10752,"thread_start_us":104,"threads_started":1,"update_count":3500}
I20260812 06:20:23.898705  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8): perf score=14.095187
I20260812 06:20:23.952538  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.053s	user 0.029s	sys 0.021s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22399,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:23.953109  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling UndoDeltaBlockGCOp(181722e80dc14a17802fe6f6068092d8): 448 bytes on disk
I20260812 06:20:23.953564  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: UndoDeltaBlockGCOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4}
I20260812 06:20:23.954030  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8): perf score=2.188937
I20260812 06:20:23.965728  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4229,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.966223  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling MajorDeltaCompactionOp(181722e80dc14a17802fe6f6068092d8): perf score=1.000000
I20260812 06:20:24.143285  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: MajorDeltaCompactionOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.177s	user 0.124s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":665,"lbm_read_time_us":13325,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27522,"lbm_writes_lt_1ms":543,"mutex_wait_us":350,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:24.143854  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8): perf score=14.095187
I20260812 06:20:24.201859  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.058s	user 0.024s	sys 0.027s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19170,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:24.202379  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8): perf score=2.188937
I20260812 06:20:24.212869  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3946,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.213330  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling MajorDeltaCompactionOp(181722e80dc14a17802fe6f6068092d8): perf score=1.000000
I20260812 06:20:24.393147  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: MajorDeltaCompactionOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.180s	user 0.100s	sys 0.068s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":402,"lbm_read_time_us":11937,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28171,"lbm_writes_lt_1ms":543,"mutex_wait_us":31,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":52224,"update_count":2500}
I20260812 06:20:24.393857  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8): perf score=14.095187
I20260812 06:20:24.447654  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.054s	user 0.024s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21063,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2000}
I20260812 06:20:24.448278  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8): perf score=2.188937
I20260812 06:20:24.468292  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.020s	user 0.005s	sys 0.014s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3921,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.468891  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling MajorDeltaCompactionOp(181722e80dc14a17802fe6f6068092d8): perf score=1.000000
I20260812 06:20:24.639156  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: MajorDeltaCompactionOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.170s	user 0.106s	sys 0.062s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":164,"lbm_read_time_us":11989,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26587,"lbm_writes_lt_1ms":543,"mutex_wait_us":29,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":31488,"update_count":2500}
I20260812 06:20:24.639746  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8): perf score=14.095187
I20260812 06:20:24.698825  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.059s	user 0.026s	sys 0.021s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22481,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:24.699371  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8): perf score=2.188937
I20260812 06:20:24.709904  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3602,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.710549  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling MajorDeltaCompactionOp(181722e80dc14a17802fe6f6068092d8): perf score=1.000000
I20260812 06:20:24.891690  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: MajorDeltaCompactionOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.181s	user 0.126s	sys 0.043s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":932,"lbm_read_time_us":11853,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28709,"lbm_writes_lt_1ms":543,"mutex_wait_us":60,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2500}
I20260812 06:20:24.892308  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8): perf score=14.095187
I20260812 06:20:24.936616  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.044s	user 0.028s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":17798,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:24.937206  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8): perf score=2.188937
I20260812 06:20:24.953341  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.016s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5789,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.953889  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling MajorDeltaCompactionOp(181722e80dc14a17802fe6f6068092d8): perf score=1.000000
I20260812 06:20:25.102787  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: MajorDeltaCompactionOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.149s	user 0.122s	sys 0.024s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":646,"lbm_read_time_us":9795,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29663,"lbm_writes_lt_1ms":543,"mutex_wait_us":325,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12160,"update_count":2500}
I20260812 06:20:25.103328  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8): perf score=11.118625
I20260812 06:20:25.140743  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.037s	user 0.028s	sys 0.008s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15620,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:25.141330  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8): perf score=2.188937
I20260812 06:20:25.164052  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.023s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4048,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:25.164608  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8): perf score=2.188937
I20260812 06:20:25.174798  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.010s	user 0.001s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3597,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.175354  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling FlushMRSOp(181722e80dc14a17802fe6f6068092d8): perf score=1.000000
I20260812 06:20:25.206272  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: FlushMRSOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.031s	user 0.025s	sys 0.004s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":61,"dirs.run_cpu_time_us":225,"dirs.run_wall_time_us":1262,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1744,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:20:25.206972  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling LogGCOp(181722e80dc14a17802fe6f6068092d8): free 133024437 bytes of WAL
I20260812 06:20:25.207201  6365 log_reader.cc:385] T 181722e80dc14a17802fe6f6068092d8: removed 13 log segments from log reader
I20260812 06:20:25.207247  6365 log.cc:1079] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/181722e80dc14a17802fe6f6068092d8/wal-000000015 (ops 70-74)
I20260812 06:20:25.207278  6365 log.cc:1079] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/181722e80dc14a17802fe6f6068092d8/wal-000000016 (ops 75-79)
I20260812 06:20:25.207310  6365 log.cc:1079] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/181722e80dc14a17802fe6f6068092d8/wal-000000017 (ops 80-84)
I20260812 06:20:25.207345  6365 log.cc:1079] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/181722e80dc14a17802fe6f6068092d8/wal-000000018 (ops 85-89)
I20260812 06:20:25.207369  6365 log.cc:1079] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/181722e80dc14a17802fe6f6068092d8/wal-000000019 (ops 90-94)
I20260812 06:20:25.207401  6365 log.cc:1079] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/181722e80dc14a17802fe6f6068092d8/wal-000000020 (ops 95-99)
I20260812 06:20:25.207432  6365 log.cc:1079] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/181722e80dc14a17802fe6f6068092d8/wal-000000021 (ops 100-104)
I20260812 06:20:25.207463  6365 log.cc:1079] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/181722e80dc14a17802fe6f6068092d8/wal-000000022 (ops 105-109)
I20260812 06:20:25.207494  6365 log.cc:1079] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/181722e80dc14a17802fe6f6068092d8/wal-000000023 (ops 110-114)
I20260812 06:20:25.207523  6365 log.cc:1079] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/181722e80dc14a17802fe6f6068092d8/wal-000000024 (ops 115-118)
I20260812 06:20:25.207574  6365 log.cc:1079] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/181722e80dc14a17802fe6f6068092d8/wal-000000025 (ops 119-123)
I20260812 06:20:25.207605  6365 log.cc:1079] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/181722e80dc14a17802fe6f6068092d8/wal-000000026 (ops 124-128)
I20260812 06:20:25.207635  6365 log.cc:1079] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/181722e80dc14a17802fe6f6068092d8/wal-000000027 (ops 129-133)
I20260812 06:20:25.234586  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: LogGCOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.027s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:20:25.235072  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8): perf score=3.181125
I20260812 06:20:25.252246  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.017s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4882121,"delete_count":0,"lbm_write_time_us":6800,"lbm_writes_lt_1ms":122,"reinsert_count":0,"update_count":595}
I20260812 06:20:25.252692  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling UndoDeltaBlockGCOp(181722e80dc14a17802fe6f6068092d8): 492 bytes on disk
I20260812 06:20:25.253091  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: UndoDeltaBlockGCOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:20:25.253600  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8): perf score=2.188937
I20260812 06:20:25.272261  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.018s	user 0.007s	sys 0.010s Metrics: {"bytes_written":3323180,"delete_count":0,"lbm_write_time_us":3088,"lbm_writes_lt_1ms":84,"reinsert_count":0,"update_count":405}
I20260812 06:20:25.272755  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling MajorDeltaCompactionOp(181722e80dc14a17802fe6f6068092d8): perf score=1.000000
I20260812 06:20:25.489346  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: MajorDeltaCompactionOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.216s	user 0.147s	sys 0.068s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":33020839,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":1199,"lbm_read_time_us":15304,"lbm_reads_lt_1ms":775,"lbm_write_time_us":34427,"lbm_writes_lt_1ms":743,"mutex_wait_us":21,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":21760,"thread_start_us":101,"threads_started":1,"update_count":3500}
I20260812 06:20:25.490046  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8): perf score=14.095187
I20260812 06:20:25.554730  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.064s	user 0.045s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":28449,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:20:25.555291  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8): perf score=3.181125
I20260812 06:20:25.566744  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4097,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:25.567233  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8): perf score=2.188937
I20260812 06:20:25.581280  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.014s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5067,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:25.581920  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling MajorDeltaCompactionOp(181722e80dc14a17802fe6f6068092d8): perf score=1.000000
I20260812 06:20:25.788933  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: MajorDeltaCompactionOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.207s	user 0.127s	sys 0.079s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918201,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1048,"lbm_read_time_us":14671,"lbm_reads_lt_1ms":673,"lbm_write_time_us":32529,"lbm_writes_lt_1ms":643,"mutex_wait_us":82,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":3000}
I20260812 06:20:25.789633  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8): perf score=14.095187
I20260812 06:20:25.838830  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.049s	user 0.036s	sys 0.008s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":20939,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:25.839362  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling MajorDeltaCompactionOp(181722e80dc14a17802fe6f6068092d8): perf score=1.000000
I20260812 06:20:25.989957  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: MajorDeltaCompactionOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.150s	user 0.099s	sys 0.042s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713155,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":197,"lbm_read_time_us":10556,"lbm_reads_lt_1ms":463,"lbm_write_time_us":23073,"lbm_writes_lt_1ms":443,"mutex_wait_us":43,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":30336,"update_count":2000}
I20260812 06:20:25.990453  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8): perf score=14.095187
I20260812 06:20:26.037416  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.047s	user 0.025s	sys 0.013s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":17425,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:26.037962  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8): perf score=2.188937
I20260812 06:20:26.049260  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4029,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.049882  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling MajorDeltaCompactionOp(181722e80dc14a17802fe6f6068092d8): perf score=1.000000
I20260812 06:20:26.234766  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: MajorDeltaCompactionOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.185s	user 0.105s	sys 0.066s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1033,"lbm_read_time_us":11644,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26881,"lbm_writes_lt_1ms":543,"mutex_wait_us":270,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:20:26.235275  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8): perf score=14.095187
I20260812 06:20:26.286769  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.051s	user 0.027s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18170,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:26.287320  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8): perf score=2.188937
I20260812 06:20:26.299325  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4081,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.300092  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling MajorDeltaCompactionOp(181722e80dc14a17802fe6f6068092d8): perf score=1.000000
I20260812 06:20:26.454910  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: MajorDeltaCompactionOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.154s	user 0.130s	sys 0.023s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1214,"lbm_read_time_us":9907,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31161,"lbm_writes_lt_1ms":543,"mutex_wait_us":337,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2500}
I20260812 06:20:26.455466  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8): perf score=11.118625
I20260812 06:20:26.492784  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.037s	user 0.024s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15844,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:26.493414  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8): perf score=2.188937
I20260812 06:20:26.517136  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.024s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4153,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:26.517699  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8): perf score=2.188937
I20260812 06:20:26.527932  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3599,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.528529  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling MajorDeltaCompactionOp(181722e80dc14a17802fe6f6068092d8): perf score=1.000000
I20260812 06:20:26.683423  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: MajorDeltaCompactionOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.155s	user 0.111s	sys 0.040s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815794,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":669,"lbm_read_time_us":11885,"lbm_reads_lt_1ms":573,"lbm_write_time_us":28500,"lbm_writes_lt_1ms":543,"mutex_wait_us":315,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2500}
I20260812 06:20:26.684067  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8): perf score=11.118625
I20260812 06:20:26.750645  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.066s	user 0.030s	sys 0.007s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":37927,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:20:26.751207  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8): perf score=6.157687
I20260812 06:20:26.771076  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.020s	user 0.010s	sys 0.007s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":8159,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:20:26.771656  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling FlushMRSOp(181722e80dc14a17802fe6f6068092d8): perf score=1.000000
I20260812 06:20:26.804661  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: FlushMRSOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.033s	user 0.031s	sys 0.001s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":88,"dirs.run_cpu_time_us":286,"dirs.run_wall_time_us":1548,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1547,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:20:26.805485  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling LogGCOp(181722e80dc14a17802fe6f6068092d8): free 133024602 bytes of WAL
I20260812 06:20:26.805830  6365 log_reader.cc:385] T 181722e80dc14a17802fe6f6068092d8: removed 13 log segments from log reader
I20260812 06:20:26.805896  6365 log.cc:1079] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/181722e80dc14a17802fe6f6068092d8/wal-000000028 (ops 134-138)
I20260812 06:20:26.805933  6365 log.cc:1079] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/181722e80dc14a17802fe6f6068092d8/wal-000000029 (ops 139-143)
I20260812 06:20:26.806018  6365 log.cc:1079] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/181722e80dc14a17802fe6f6068092d8/wal-000000030 (ops 144-148)
I20260812 06:20:26.806066  6365 log.cc:1079] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/181722e80dc14a17802fe6f6068092d8/wal-000000031 (ops 149-152)
I20260812 06:20:26.806097  6365 log.cc:1079] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/181722e80dc14a17802fe6f6068092d8/wal-000000032 (ops 153-157)
I20260812 06:20:26.806192  6365 log.cc:1079] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/181722e80dc14a17802fe6f6068092d8/wal-000000033 (ops 158-162)
I20260812 06:20:26.806252  6365 log.cc:1079] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/181722e80dc14a17802fe6f6068092d8/wal-000000034 (ops 163-167)
I20260812 06:20:26.806282  6365 log.cc:1079] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/181722e80dc14a17802fe6f6068092d8/wal-000000035 (ops 168-172)
I20260812 06:20:26.806398  6365 log.cc:1079] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/181722e80dc14a17802fe6f6068092d8/wal-000000036 (ops 173-176)
I20260812 06:20:26.806458  6365 log.cc:1079] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/181722e80dc14a17802fe6f6068092d8/wal-000000037 (ops 177-181)
I20260812 06:20:26.806551  6365 log.cc:1079] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/181722e80dc14a17802fe6f6068092d8/wal-000000038 (ops 182-186)
I20260812 06:20:26.806604  6365 log.cc:1079] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/181722e80dc14a17802fe6f6068092d8/wal-000000039 (ops 187-191)
I20260812 06:20:26.806640  6365 log.cc:1079] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd: Deleting log segment in path: /tmp/dist-test-tasku523H8/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616645234-5862-0/minicluster-data/ts-0-root/wals/181722e80dc14a17802fe6f6068092d8/wal-000000040 (ops 192-197)
I20260812 06:20:26.835777  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: LogGCOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.030s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:20:26.836179  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8): perf score=6.157687
I20260812 06:20:26.855937  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: FlushDeltaMemStoresOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.020s	user 0.010s	sys 0.009s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":8115,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:20:26.856446  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling UndoDeltaBlockGCOp(181722e80dc14a17802fe6f6068092d8): 492 bytes on disk
I20260812 06:20:26.856848  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: UndoDeltaBlockGCOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4}
I20260812 06:20:26.857343  6482 maintenance_manager.cc:419] P 8c9f8ddc558d444890bcf4dfddee61dd: Scheduling MajorDeltaCompactionOp(181722e80dc14a17802fe6f6068092d8): perf score=1.000000
I20260812 06:20:26.888095  5862 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.795s	user 1.685s	sys 0.179s
I20260812 06:20:26.980985  5862 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.092s	user 0.003s	sys 0.000s
I20260812 06:20:26.981631  5862 tablet_server.cc:179] TabletServer@127.5.185.129:0 shutting down...
I20260812 06:20:27.055845  6365 maintenance_manager.cc:643] P 8c9f8ddc558d444890bcf4dfddee61dd: MajorDeltaCompactionOp(181722e80dc14a17802fe6f6068092d8) complete. Timing: real 0.198s	user 0.146s	sys 0.046s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":33020633,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":887,"lbm_read_time_us":15541,"lbm_reads_lt_1ms":765,"lbm_write_time_us":31317,"lbm_writes_lt_1ms":743,"mutex_wait_us":56,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":18816,"thread_start_us":88,"threads_started":1,"update_count":3500}
I20260812 06:20:27.056452  5862 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:27.056671  5862 tablet_replica.cc:333] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd: stopping tablet replica
I20260812 06:20:27.056797  5862 raft_consensus.cc:2243] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:27.056988  5862 raft_consensus.cc:2272] T 181722e80dc14a17802fe6f6068092d8 P 8c9f8ddc558d444890bcf4dfddee61dd [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:27.061537  5862 tablet_server.cc:196] TabletServer@127.5.185.129:0 shutdown complete.
I20260812 06:20:27.112519  5862 master.cc:562] Master@127.5.185.190:44331 shutting down...
I20260812 06:20:27.117285  5862 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 83470e201556479cb4d52573a8a3d08e [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:27.117506  5862 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 83470e201556479cb4d52573a8a3d08e [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:27.117580  5862 tablet_replica.cc:333] T 00000000000000000000000000000000 P 83470e201556479cb4d52573a8a3d08e: stopping tablet replica
I20260812 06:20:27.129897  5862 master.cc:584] Master@127.5.185.190:44331 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5320 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10551 ms total)

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