[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:19:27.770231  4858 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.4.190.190:42977
I20260812 06:19:27.771251  4858 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:19:27.771829  4858 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:27.778286  4871 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:27.778383  4858 server_base.cc:1061] running on GCE node
W20260812 06:19:27.778316  4866 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:27.778628  4868 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:27.779179  4858 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:27.779317  4858 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:27.779374  4858 hybrid_clock.cc:648] HybridClock initialized: now 1786515567779372 us; error 0 us; skew 500 ppm
I20260812 06:19:27.781204  4858 webserver.cc:533] Webserver started at http://127.4.190.190:34941/ using document root <none> and password file <none>
I20260812 06:19:27.781792  4858 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:27.781894  4858 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:27.782183  4858 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:27.783886  4858 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567759193-4858-0/minicluster-data/master-0-root/instance:
uuid: "01a6015d22d94a07b4097aa3f5587f75"
format_stamp: "Formatted at 2026-08-12 06:19:27 on dist-test-slave-7kzw"
I20260812 06:19:27.787405  4858 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:19:27.789458  4880 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:27.790457  4858 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.001s
I20260812 06:19:27.790640  4858 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567759193-4858-0/minicluster-data/master-0-root
uuid: "01a6015d22d94a07b4097aa3f5587f75"
format_stamp: "Formatted at 2026-08-12 06:19:27 on dist-test-slave-7kzw"
I20260812 06:19:27.790745  4858 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567759193-4858-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567759193-4858-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567759193-4858-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:27.804790  4858 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:27.805503  4858 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:19:27.805688  4858 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:27.813647  4858 rpc_server.cc:307] RPC server started. Bound to: 127.4.190.190:42977
I20260812 06:19:27.813683  4972 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.4.190.190:42977 every 8 connection(s)
I20260812 06:19:27.815944  4973 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:27.821431  4973 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 01a6015d22d94a07b4097aa3f5587f75: Bootstrap starting.
I20260812 06:19:27.823833  4973 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 01a6015d22d94a07b4097aa3f5587f75: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:27.824725  4973 log.cc:826] T 00000000000000000000000000000000 P 01a6015d22d94a07b4097aa3f5587f75: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:27.826409  4973 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 01a6015d22d94a07b4097aa3f5587f75: No bootstrap required, opened a new log
I20260812 06:19:27.829152  4973 raft_consensus.cc:359] T 00000000000000000000000000000000 P 01a6015d22d94a07b4097aa3f5587f75 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "01a6015d22d94a07b4097aa3f5587f75" member_type: VOTER }
I20260812 06:19:27.829315  4973 raft_consensus.cc:385] T 00000000000000000000000000000000 P 01a6015d22d94a07b4097aa3f5587f75 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:27.829394  4973 raft_consensus.cc:740] T 00000000000000000000000000000000 P 01a6015d22d94a07b4097aa3f5587f75 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 01a6015d22d94a07b4097aa3f5587f75, State: Initialized, Role: FOLLOWER
I20260812 06:19:27.830070  4973 consensus_queue.cc:260] T 00000000000000000000000000000000 P 01a6015d22d94a07b4097aa3f5587f75 [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: "01a6015d22d94a07b4097aa3f5587f75" member_type: VOTER }
I20260812 06:19:27.830240  4973 raft_consensus.cc:399] T 00000000000000000000000000000000 P 01a6015d22d94a07b4097aa3f5587f75 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:27.830317  4973 raft_consensus.cc:493] T 00000000000000000000000000000000 P 01a6015d22d94a07b4097aa3f5587f75 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:27.830493  4973 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 01a6015d22d94a07b4097aa3f5587f75 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:27.831280  4973 raft_consensus.cc:515] T 00000000000000000000000000000000 P 01a6015d22d94a07b4097aa3f5587f75 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "01a6015d22d94a07b4097aa3f5587f75" member_type: VOTER }
I20260812 06:19:27.831728  4973 leader_election.cc:304] T 00000000000000000000000000000000 P 01a6015d22d94a07b4097aa3f5587f75 [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: 01a6015d22d94a07b4097aa3f5587f75; no voters: 
I20260812 06:19:27.832052  4973 leader_election.cc:290] T 00000000000000000000000000000000 P 01a6015d22d94a07b4097aa3f5587f75 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:27.832231  4977 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 01a6015d22d94a07b4097aa3f5587f75 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:27.832497  4977 raft_consensus.cc:697] T 00000000000000000000000000000000 P 01a6015d22d94a07b4097aa3f5587f75 [term 1 LEADER]: Becoming Leader. State: Replica: 01a6015d22d94a07b4097aa3f5587f75, State: Running, Role: LEADER
I20260812 06:19:27.832852  4977 consensus_queue.cc:237] T 00000000000000000000000000000000 P 01a6015d22d94a07b4097aa3f5587f75 [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: "01a6015d22d94a07b4097aa3f5587f75" member_type: VOTER }
I20260812 06:19:27.833107  4973 sys_catalog.cc:565] T 00000000000000000000000000000000 P 01a6015d22d94a07b4097aa3f5587f75 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:27.834964  4978 sys_catalog.cc:455] T 00000000000000000000000000000000 P 01a6015d22d94a07b4097aa3f5587f75 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "01a6015d22d94a07b4097aa3f5587f75" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "01a6015d22d94a07b4097aa3f5587f75" member_type: VOTER } }
I20260812 06:19:27.834944  4982 sys_catalog.cc:455] T 00000000000000000000000000000000 P 01a6015d22d94a07b4097aa3f5587f75 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 01a6015d22d94a07b4097aa3f5587f75. Latest consensus state: current_term: 1 leader_uuid: "01a6015d22d94a07b4097aa3f5587f75" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "01a6015d22d94a07b4097aa3f5587f75" member_type: VOTER } }
I20260812 06:19:27.835093  4982 sys_catalog.cc:458] T 00000000000000000000000000000000 P 01a6015d22d94a07b4097aa3f5587f75 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:27.835093  4978 sys_catalog.cc:458] T 00000000000000000000000000000000 P 01a6015d22d94a07b4097aa3f5587f75 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:27.835376  4858 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:19:27.837335  5002 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 01a6015d22d94a07b4097aa3f5587f75: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:19:27.837423  5002 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:19:27.837508  4999 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:27.838258  4999 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:27.842962  4999 catalog_manager.cc:1383] Generated new cluster ID: 6e06ae2add7944acb39329b236c83519
I20260812 06:19:27.843014  4999 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:27.865664  4999 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:27.866891  4999 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:27.876300  4999 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 01a6015d22d94a07b4097aa3f5587f75: Generated new TSK 0
I20260812 06:19:27.877023  4999 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:27.900214  4858 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:27.903234  5008 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:27.903252  5012 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:27.903525  5010 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:27.903537  4858 server_base.cc:1061] running on GCE node
I20260812 06:19:27.903829  4858 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:27.903894  4858 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:27.903929  4858 hybrid_clock.cc:648] HybridClock initialized: now 1786515567903928 us; error 0 us; skew 500 ppm
I20260812 06:19:27.904976  4858 webserver.cc:533] Webserver started at http://127.4.190.129:42953/ using document root <none> and password file <none>
I20260812 06:19:27.905158  4858 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:27.905237  4858 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:27.905318  4858 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:27.905745  4858 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567759193-4858-0/minicluster-data/ts-0-root/instance:
uuid: "cd87b83c69e945748493d323b1ab369d"
format_stamp: "Formatted at 2026-08-12 06:19:27 on dist-test-slave-7kzw"
I20260812 06:19:27.907440  4858 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:19:27.908488  5020 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:27.908753  4858 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:27.908834  4858 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567759193-4858-0/minicluster-data/ts-0-root
uuid: "cd87b83c69e945748493d323b1ab369d"
format_stamp: "Formatted at 2026-08-12 06:19:27 on dist-test-slave-7kzw"
I20260812 06:19:27.908923  4858 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567759193-4858-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567759193-4858-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567759193-4858-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:27.927546  4858 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:27.928028  4858 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:27.928563  4858 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:27.929471  4858 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:27.929523  4858 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:27.929598  4858 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:27.929647  4858 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:27.936545  4858 rpc_server.cc:307] RPC server started. Bound to: 127.4.190.129:42079
I20260812 06:19:27.936640  5113 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.4.190.129:42079 every 8 connection(s)
I20260812 06:19:27.947582  5116 heartbeater.cc:344] Connected to a master server at 127.4.190.190:42977
I20260812 06:19:27.947845  5116 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:27.948330  5116 heartbeater.cc:507] Master 127.4.190.190:42977 requested a full tablet report, sending...
I20260812 06:19:27.949780  4912 ts_manager.cc:194] Registered new tserver with Master: cd87b83c69e945748493d323b1ab369d (127.4.190.129:42079)
I20260812 06:19:27.950034  4858 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012826364s
I20260812 06:19:27.951373  4912 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:51280
I20260812 06:19:27.960276  4912 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:51284:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:27.974923  5063 tablet_service.cc:1511] Processing CreateTablet for tablet a510b20ce2cb460eb59ce4b456ef8bd9 (DEFAULT_TABLE table=heavy-update-compaction-test [id=f49cc013179e49269caf3c3565b7e2c6]), partition=
I20260812 06:19:27.975449  5063 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet a510b20ce2cb460eb59ce4b456ef8bd9. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:27.977764  5138 tablet_bootstrap.cc:492] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d: Bootstrap starting.
I20260812 06:19:27.979251  5138 tablet_bootstrap.cc:654] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:27.980499  5138 tablet_bootstrap.cc:492] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d: No bootstrap required, opened a new log
I20260812 06:19:27.980592  5138 ts_tablet_manager.cc:1403] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d: Time spent bootstrapping tablet: real 0.003s	user 0.000s	sys 0.002s
I20260812 06:19:27.981146  5138 raft_consensus.cc:359] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "cd87b83c69e945748493d323b1ab369d" member_type: VOTER last_known_addr { host: "127.4.190.129" port: 42079 } }
I20260812 06:19:27.981257  5138 raft_consensus.cc:385] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:27.981284  5138 raft_consensus.cc:740] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: cd87b83c69e945748493d323b1ab369d, State: Initialized, Role: FOLLOWER
I20260812 06:19:27.981551  5138 consensus_queue.cc:260] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d [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: "cd87b83c69e945748493d323b1ab369d" member_type: VOTER last_known_addr { host: "127.4.190.129" port: 42079 } }
I20260812 06:19:27.981642  5138 raft_consensus.cc:399] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:27.981673  5138 raft_consensus.cc:493] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:27.981763  5138 raft_consensus.cc:3060] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:27.982923  5138 raft_consensus.cc:515] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "cd87b83c69e945748493d323b1ab369d" member_type: VOTER last_known_addr { host: "127.4.190.129" port: 42079 } }
I20260812 06:19:27.983093  5138 leader_election.cc:304] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d [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: cd87b83c69e945748493d323b1ab369d; no voters: 
I20260812 06:19:27.983366  5138 leader_election.cc:290] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:27.983469  5140 raft_consensus.cc:2804] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:27.983657  5140 raft_consensus.cc:697] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d [term 1 LEADER]: Becoming Leader. State: Replica: cd87b83c69e945748493d323b1ab369d, State: Running, Role: LEADER
I20260812 06:19:27.983783  5138 ts_tablet_manager.cc:1434] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d: Time spent starting tablet: real 0.003s	user 0.002s	sys 0.001s
I20260812 06:19:27.983878  5140 consensus_queue.cc:237] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d [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: "cd87b83c69e945748493d323b1ab369d" member_type: VOTER last_known_addr { host: "127.4.190.129" port: 42079 } }
I20260812 06:19:27.983981  5116 heartbeater.cc:499] Master 127.4.190.190:42977 was elected leader, sending a full tablet report...
I20260812 06:19:27.986845  4912 catalog_manager.cc:5719] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d reported cstate change: term changed from 0 to 1, leader changed from <none> to cd87b83c69e945748493d323b1ab369d (127.4.190.129). New cstate: current_term: 1 leader_uuid: "cd87b83c69e945748493d323b1ab369d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "cd87b83c69e945748493d323b1ab369d" member_type: VOTER last_known_addr { host: "127.4.190.129" port: 42079 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:28.050814  4858 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.055s	user 0.014s	sys 0.011s
I20260812 06:19:28.187698  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling FlushMRSOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=19.054940
I20260812 06:19:28.405689  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: FlushMRSOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.218s	user 0.167s	sys 0.044s Metrics: {"bytes_written":15261224,"cfile_init":1,"compiler_manager_pool.queue_time_us":253,"delete_count":0,"dirs.queue_time_us":84,"dirs.run_cpu_time_us":260,"dirs.run_wall_time_us":795,"drs_written":1,"lbm_read_time_us":78,"lbm_reads_lt_1ms":4,"lbm_write_time_us":53206,"lbm_writes_lt_1ms":829,"mutex_wait_us":2335,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":126720,"thread_start_us":171,"threads_started":1,"update_count":1860}
I20260812 06:19:28.406934  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling LogGCOp(a510b20ce2cb460eb59ce4b456ef8bd9): free 20743880 bytes of WAL
I20260812 06:19:28.407267  5028 log_reader.cc:385] T a510b20ce2cb460eb59ce4b456ef8bd9: removed 2 log segments from log reader
I20260812 06:19:28.407361  5028 log.cc:1079] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/a510b20ce2cb460eb59ce4b456ef8bd9/wal-000000001 (ops 1-6)
I20260812 06:19:28.407439  5028 log.cc:1079] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/a510b20ce2cb460eb59ce4b456ef8bd9/wal-000000002 (ops 7-11)
I20260812 06:19:28.411928  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: LogGCOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.005s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:19:28.412276  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=4.173312
I20260812 06:19:28.425961  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.014s	user 0.011s	sys 0.000s Metrics: {"bytes_written":5251342,"delete_count":0,"lbm_write_time_us":5277,"lbm_writes_lt_1ms":131,"reinsert_count":0,"update_count":640}
I20260812 06:19:28.426689  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling MajorDeltaCompactionOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=1.000000
I20260812 06:19:28.596902  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: MajorDeltaCompactionOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.170s	user 0.145s	sys 0.024s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":520,"lbm_read_time_us":13493,"lbm_reads_lt_1ms":568,"lbm_write_time_us":27707,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12544,"thread_start_us":318,"threads_started":5,"update_count":2500}
I20260812 06:19:28.597496  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=10.126437
I20260812 06:19:28.636323  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.039s	user 0.021s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16616,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:28.636848  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling UndoDeltaBlockGCOp(a510b20ce2cb460eb59ce4b456ef8bd9): 16411393 bytes on disk
I20260812 06:19:28.637383  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: UndoDeltaBlockGCOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:19:28.638094  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=2.188937
I20260812 06:19:28.649144  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3960,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:28.649592  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling MajorDeltaCompactionOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=1.000000
I20260812 06:19:28.776197  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: MajorDeltaCompactionOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.126s	user 0.098s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1448,"lbm_read_time_us":9300,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23984,"lbm_writes_lt_1ms":443,"mutex_wait_us":360,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:19:28.776737  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=10.126437
I20260812 06:19:28.827610  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.051s	user 0.030s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17275,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:28.828106  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=2.188937
I20260812 06:19:28.839871  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.012s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4321,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:28.840605  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling MajorDeltaCompactionOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=1.000000
I20260812 06:19:28.991240  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: MajorDeltaCompactionOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.150s	user 0.100s	sys 0.046s 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":1493,"lbm_read_time_us":9613,"lbm_reads_lt_1ms":472,"lbm_write_time_us":34266,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":543,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2000}
I20260812 06:19:28.992018  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=11.118625
I20260812 06:19:29.033865  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.040s	user 0.022s	sys 0.015s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":18009,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:29.034430  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=2.188937
I20260812 06:19:29.044760  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3897,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:29.045423  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling MajorDeltaCompactionOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=1.000000
I20260812 06:19:29.178289  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: MajorDeltaCompactionOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.133s	user 0.116s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672269,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":410,"lbm_read_time_us":9490,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27382,"lbm_writes_lt_1ms":443,"mutex_wait_us":101,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":134272,"update_count":2000}
I20260812 06:19:29.179008  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=10.126437
I20260812 06:19:29.225616  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.046s	user 0.029s	sys 0.014s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16465,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:29.226356  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=2.188937
I20260812 06:19:29.243532  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.017s	user 0.007s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6580,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:29.244168  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling MajorDeltaCompactionOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=1.000000
I20260812 06:19:29.390738  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: MajorDeltaCompactionOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.146s	user 0.094s	sys 0.047s 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":398,"lbm_read_time_us":10434,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23540,"lbm_writes_lt_1ms":443,"mutex_wait_us":49,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":21248,"update_count":2000}
I20260812 06:19:29.391366  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=10.126437
I20260812 06:19:29.438937  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.047s	user 0.025s	sys 0.013s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16892,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:29.439404  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=2.188937
I20260812 06:19:29.449541  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3960,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:29.449973  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling MajorDeltaCompactionOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=1.000000
I20260812 06:19:29.573874  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: MajorDeltaCompactionOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.124s	user 0.104s	sys 0.020s 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":306,"lbm_read_time_us":8803,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24764,"lbm_writes_lt_1ms":443,"mutex_wait_us":25,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5632,"update_count":2000}
I20260812 06:19:29.574435  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=10.126437
I20260812 06:19:29.606998  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.032s	user 0.010s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13707,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:29.607513  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling FlushMRSOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=1.000000
I20260812 06:19:29.649466  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: FlushMRSOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.042s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":276,"dirs.run_wall_time_us":1466,"drs_written":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1990,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:29.650269  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling UndoDeltaBlockGCOp(a510b20ce2cb460eb59ce4b456ef8bd9): 462 bytes on disk
I20260812 06:19:29.650719  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: UndoDeltaBlockGCOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:19:29.651158  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=3.181125
I20260812 06:19:29.666085  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.015s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":4549,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:29.666656  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling LogGCOp(a510b20ce2cb460eb59ce4b456ef8bd9): free 112239270 bytes of WAL
I20260812 06:19:29.667033  5028 log_reader.cc:385] T a510b20ce2cb460eb59ce4b456ef8bd9: removed 11 log segments from log reader
I20260812 06:19:29.667105  5028 log.cc:1079] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/a510b20ce2cb460eb59ce4b456ef8bd9/wal-000000003 (ops 12-16)
I20260812 06:19:29.667157  5028 log.cc:1079] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/a510b20ce2cb460eb59ce4b456ef8bd9/wal-000000004 (ops 17-21)
I20260812 06:19:29.667204  5028 log.cc:1079] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/a510b20ce2cb460eb59ce4b456ef8bd9/wal-000000005 (ops 22-26)
I20260812 06:19:29.667258  5028 log.cc:1079] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/a510b20ce2cb460eb59ce4b456ef8bd9/wal-000000006 (ops 27-30)
I20260812 06:19:29.667315  5028 log.cc:1079] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/a510b20ce2cb460eb59ce4b456ef8bd9/wal-000000007 (ops 31-35)
I20260812 06:19:29.667351  5028 log.cc:1079] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/a510b20ce2cb460eb59ce4b456ef8bd9/wal-000000008 (ops 36-40)
I20260812 06:19:29.667388  5028 log.cc:1079] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/a510b20ce2cb460eb59ce4b456ef8bd9/wal-000000009 (ops 41-45)
I20260812 06:19:29.667426  5028 log.cc:1079] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/a510b20ce2cb460eb59ce4b456ef8bd9/wal-000000010 (ops 46-50)
I20260812 06:19:29.667462  5028 log.cc:1079] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/a510b20ce2cb460eb59ce4b456ef8bd9/wal-000000011 (ops 51-55)
I20260812 06:19:29.667502  5028 log.cc:1079] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/a510b20ce2cb460eb59ce4b456ef8bd9/wal-000000012 (ops 56-60)
I20260812 06:19:29.667539  5028 log.cc:1079] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/a510b20ce2cb460eb59ce4b456ef8bd9/wal-000000013 (ops 61-65)
I20260812 06:19:29.693966  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: LogGCOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.027s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:19:29.694623  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=2.188937
I20260812 06:19:29.713307  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.018s	user 0.002s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4887,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:29.713759  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=2.188937
I20260812 06:19:29.724124  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4069,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:29.724570  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling MajorDeltaCompactionOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=1.000000
I20260812 06:19:29.907358  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: MajorDeltaCompactionOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.183s	user 0.154s	sys 0.023s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877325,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1399,"lbm_read_time_us":13415,"lbm_reads_lt_1ms":674,"lbm_write_time_us":35686,"lbm_writes_lt_1ms":643,"mutex_wait_us":276,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3712,"thread_start_us":96,"threads_started":1,"update_count":3000}
I20260812 06:19:29.908020  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=14.095187
I20260812 06:19:29.961088  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.053s	user 0.018s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19598,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:29.961752  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=2.188937
I20260812 06:19:29.974066  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4523,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:29.974697  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling MajorDeltaCompactionOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=1.000000
I20260812 06:19:30.145157  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: MajorDeltaCompactionOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.170s	user 0.139s	sys 0.020s 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":335,"lbm_read_time_us":11101,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31632,"lbm_writes_lt_1ms":543,"mutex_wait_us":55,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16128,"update_count":2500}
I20260812 06:19:30.145893  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=14.095187
I20260812 06:19:30.204037  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.058s	user 0.034s	sys 0.016s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":22415,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:30.204574  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=2.188937
I20260812 06:19:30.217980  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.013s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4661,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:30.218534  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling MajorDeltaCompactionOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=1.000000
I20260812 06:19:30.389561  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: MajorDeltaCompactionOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.171s	user 0.135s	sys 0.025s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":139,"lbm_read_time_us":12239,"lbm_reads_lt_1ms":564,"lbm_write_time_us":32241,"lbm_writes_lt_1ms":543,"mutex_wait_us":28,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":45184,"update_count":2500}
I20260812 06:19:30.390218  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=14.095187
I20260812 06:19:30.443265  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.053s	user 0.045s	sys 0.007s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23351,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:30.443804  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=2.188937
I20260812 06:19:30.457262  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4820,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:30.457850  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling MajorDeltaCompactionOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=1.000000
I20260812 06:19:30.635867  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: MajorDeltaCompactionOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.178s	user 0.138s	sys 0.022s 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":1071,"lbm_read_time_us":12063,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34132,"lbm_writes_lt_1ms":543,"mutex_wait_us":559,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2500}
I20260812 06:19:30.636574  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=14.095187
I20260812 06:19:30.695700  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.059s	user 0.026s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21156,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:30.696152  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=2.188937
I20260812 06:19:30.706378  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3844,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:30.706847  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling MajorDeltaCompactionOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=1.000000
I20260812 06:19:30.886745  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: MajorDeltaCompactionOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.180s	user 0.123s	sys 0.048s 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":624,"lbm_read_time_us":10891,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29458,"lbm_writes_lt_1ms":543,"mutex_wait_us":284,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9472,"update_count":2500}
I20260812 06:19:30.887385  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=14.095187
I20260812 06:19:30.946641  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.059s	user 0.039s	sys 0.016s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":25184,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:30.947124  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling MajorDeltaCompactionOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=1.000000
I20260812 06:19:31.106603  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: MajorDeltaCompactionOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.159s	user 0.104s	sys 0.041s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672156,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":588,"lbm_read_time_us":9141,"lbm_reads_lt_1ms":463,"lbm_write_time_us":26577,"lbm_writes_lt_1ms":443,"mutex_wait_us":41,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:31.107349  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=14.095187
I20260812 06:19:31.160449  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.053s	user 0.030s	sys 0.016s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":21606,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:31.160931  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=2.188937
I20260812 06:19:31.171412  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3916,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:31.172065  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling FlushMRSOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=1.000000
I20260812 06:19:31.210525  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: FlushMRSOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.038s	user 0.035s	sys 0.004s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":117,"dirs.run_cpu_time_us":315,"dirs.run_wall_time_us":1424,"drs_written":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2172,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:31.211411  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling LogGCOp(a510b20ce2cb460eb59ce4b456ef8bd9): free 133024367 bytes of WAL
I20260812 06:19:31.211705  5028 log_reader.cc:385] T a510b20ce2cb460eb59ce4b456ef8bd9: removed 13 log segments from log reader
I20260812 06:19:31.211781  5028 log.cc:1079] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/a510b20ce2cb460eb59ce4b456ef8bd9/wal-000000014 (ops 66-70)
I20260812 06:19:31.211822  5028 log.cc:1079] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/a510b20ce2cb460eb59ce4b456ef8bd9/wal-000000015 (ops 71-75)
I20260812 06:19:31.211848  5028 log.cc:1079] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/a510b20ce2cb460eb59ce4b456ef8bd9/wal-000000016 (ops 76-80)
I20260812 06:19:31.211871  5028 log.cc:1079] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/a510b20ce2cb460eb59ce4b456ef8bd9/wal-000000017 (ops 81-84)
I20260812 06:19:31.211899  5028 log.cc:1079] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/a510b20ce2cb460eb59ce4b456ef8bd9/wal-000000018 (ops 85-89)
I20260812 06:19:31.211934  5028 log.cc:1079] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/a510b20ce2cb460eb59ce4b456ef8bd9/wal-000000019 (ops 90-94)
I20260812 06:19:31.211966  5028 log.cc:1079] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/a510b20ce2cb460eb59ce4b456ef8bd9/wal-000000020 (ops 95-99)
I20260812 06:19:31.211995  5028 log.cc:1079] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/a510b20ce2cb460eb59ce4b456ef8bd9/wal-000000021 (ops 100-104)
I20260812 06:19:31.212024  5028 log.cc:1079] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/a510b20ce2cb460eb59ce4b456ef8bd9/wal-000000022 (ops 105-109)
I20260812 06:19:31.212046  5028 log.cc:1079] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/a510b20ce2cb460eb59ce4b456ef8bd9/wal-000000023 (ops 110-114)
I20260812 06:19:31.212076  5028 log.cc:1079] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/a510b20ce2cb460eb59ce4b456ef8bd9/wal-000000024 (ops 115-119)
I20260812 06:19:31.212108  5028 log.cc:1079] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/a510b20ce2cb460eb59ce4b456ef8bd9/wal-000000025 (ops 120-124)
I20260812 06:19:31.212138  5028 log.cc:1079] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/a510b20ce2cb460eb59ce4b456ef8bd9/wal-000000026 (ops 125-129)
I20260812 06:19:31.247007  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: LogGCOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.035s	user 0.000s	sys 0.035s Metrics: {}
I20260812 06:19:31.247506  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=3.181125
I20260812 06:19:31.265300  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.018s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":4468,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:31.265779  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling UndoDeltaBlockGCOp(a510b20ce2cb460eb59ce4b456ef8bd9): 483 bytes on disk
I20260812 06:19:31.266177  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: UndoDeltaBlockGCOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:19:31.266835  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=2.188937
I20260812 06:19:31.276139  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.009s	user 0.000s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3550,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:31.276536  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling MajorDeltaCompactionOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=1.000000
I20260812 06:19:31.518232  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: MajorDeltaCompactionOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.242s	user 0.156s	sys 0.076s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979739,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":630,"lbm_read_time_us":14760,"lbm_reads_lt_1ms":774,"lbm_write_time_us":38983,"lbm_writes_lt_1ms":743,"mutex_wait_us":49,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":10368,"thread_start_us":76,"threads_started":1,"update_count":3500}
I20260812 06:19:31.519040  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=18.063937
I20260812 06:19:31.590606  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.071s	user 0.036s	sys 0.027s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":28096,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:31.591064  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=2.188937
I20260812 06:19:31.602233  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.011s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3977,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:31.602902  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling MajorDeltaCompactionOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=1.000000
I20260812 06:19:31.817679  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: MajorDeltaCompactionOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.215s	user 0.149s	sys 0.065s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":567,"lbm_read_time_us":14977,"lbm_reads_lt_1ms":672,"lbm_write_time_us":38025,"lbm_writes_lt_1ms":643,"mutex_wait_us":318,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":25984,"update_count":3000}
I20260812 06:19:31.818521  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=14.095187
I20260812 06:19:31.869936  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.051s	user 0.038s	sys 0.009s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":22087,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:31.870616  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=2.188937
I20260812 06:19:31.885885  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5905,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:31.886523  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling MajorDeltaCompactionOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=1.000000
I20260812 06:19:32.081120  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: MajorDeltaCompactionOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.194s	user 0.138s	sys 0.053s 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":182,"lbm_read_time_us":14454,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31675,"lbm_writes_lt_1ms":543,"mutex_wait_us":50,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14080,"update_count":2500}
I20260812 06:19:32.081826  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=14.095187
I20260812 06:19:32.142499  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.060s	user 0.032s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19980,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:32.143018  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=2.188937
I20260812 06:19:32.155318  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4600,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:32.157701  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling MajorDeltaCompactionOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=1.000000
I20260812 06:19:32.340950  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: MajorDeltaCompactionOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.183s	user 0.123s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1079,"lbm_read_time_us":12612,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34657,"lbm_writes_lt_1ms":543,"mutex_wait_us":345,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9984,"update_count":2500}
I20260812 06:19:32.341509  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=14.095187
I20260812 06:19:32.406036  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.064s	user 0.038s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24504,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:32.406706  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=2.188937
I20260812 06:19:32.426815  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.020s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5075,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:32.427636  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling MajorDeltaCompactionOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=1.000000
I20260812 06:19:32.611641  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: MajorDeltaCompactionOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.184s	user 0.117s	sys 0.067s 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":249,"lbm_read_time_us":12556,"lbm_reads_lt_1ms":564,"lbm_write_time_us":32346,"lbm_writes_lt_1ms":543,"mutex_wait_us":77,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:19:32.612411  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=14.095187
I20260812 06:19:32.659883  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.047s	user 0.021s	sys 0.021s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19487,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:32.660475  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=2.188937
I20260812 06:19:32.684860  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.024s	user 0.011s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4996,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:32.685499  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling FlushMRSOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=1.000000
I20260812 06:19:32.716881  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: FlushMRSOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.031s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":82,"dirs.run_cpu_time_us":262,"dirs.run_wall_time_us":1308,"drs_written":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1982,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:32.717701  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling LogGCOp(a510b20ce2cb460eb59ce4b456ef8bd9): free 116849825 bytes of WAL
I20260812 06:19:32.717985  5028 log_reader.cc:385] T a510b20ce2cb460eb59ce4b456ef8bd9: removed 12 log segments from log reader
I20260812 06:19:32.718051  5028 log.cc:1079] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/a510b20ce2cb460eb59ce4b456ef8bd9/wal-000000027 (ops 130-134)
I20260812 06:19:32.718092  5028 log.cc:1079] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/a510b20ce2cb460eb59ce4b456ef8bd9/wal-000000028 (ops 135-138)
I20260812 06:19:32.718115  5028 log.cc:1079] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/a510b20ce2cb460eb59ce4b456ef8bd9/wal-000000029 (ops 139-143)
I20260812 06:19:32.718137  5028 log.cc:1079] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/a510b20ce2cb460eb59ce4b456ef8bd9/wal-000000030 (ops 144-148)
I20260812 06:19:32.718159  5028 log.cc:1079] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/a510b20ce2cb460eb59ce4b456ef8bd9/wal-000000031 (ops 149-152)
I20260812 06:19:32.718194  5028 log.cc:1079] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/a510b20ce2cb460eb59ce4b456ef8bd9/wal-000000032 (ops 153-157)
I20260812 06:19:32.718228  5028 log.cc:1079] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/a510b20ce2cb460eb59ce4b456ef8bd9/wal-000000033 (ops 158-162)
I20260812 06:19:32.718259  5028 log.cc:1079] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/a510b20ce2cb460eb59ce4b456ef8bd9/wal-000000034 (ops 163-167)
I20260812 06:19:32.718289  5028 log.cc:1079] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/a510b20ce2cb460eb59ce4b456ef8bd9/wal-000000035 (ops 168-172)
I20260812 06:19:32.718318  5028 log.cc:1079] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/a510b20ce2cb460eb59ce4b456ef8bd9/wal-000000036 (ops 173-176)
I20260812 06:19:32.718344  5028 log.cc:1079] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/a510b20ce2cb460eb59ce4b456ef8bd9/wal-000000037 (ops 177-181)
I20260812 06:19:32.718377  5028 log.cc:1079] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/a510b20ce2cb460eb59ce4b456ef8bd9/wal-000000038 (ops 182-186)
I20260812 06:19:32.746949  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: LogGCOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.029s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:19:32.747459  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=2.188937
I20260812 06:19:32.773568  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.026s	user 0.004s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4840,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:32.774055  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling UndoDeltaBlockGCOp(a510b20ce2cb460eb59ce4b456ef8bd9): 446 bytes on disk
I20260812 06:19:32.774523  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: UndoDeltaBlockGCOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:19:32.775056  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=2.188937
I20260812 06:19:32.785351  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3943,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:32.785754  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling MajorDeltaCompactionOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=1.000000
I20260812 06:19:33.034557  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: MajorDeltaCompactionOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.249s	user 0.120s	sys 0.120s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979751,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":315,"lbm_read_time_us":15853,"lbm_reads_lt_1ms":774,"lbm_write_time_us":41765,"lbm_writes_lt_1ms":743,"mutex_wait_us":24,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":21632,"thread_start_us":86,"threads_started":1,"update_count":3500}
I20260812 06:19:33.035403  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=18.063937
I20260812 06:19:33.102056  4858 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.051s	user 1.874s	sys 0.149s
I20260812 06:19:33.106169  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.071s	user 0.025s	sys 0.028s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":25359,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:33.106775  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=2.188937
I20260812 06:19:33.123512  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: FlushDeltaMemStoresOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.017s	user 0.011s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6466,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":500}
I20260812 06:19:33.124148  5118 maintenance_manager.cc:419] P cd87b83c69e945748493d323b1ab369d: Scheduling MajorDeltaCompactionOp(a510b20ce2cb460eb59ce4b456ef8bd9): perf score=1.000000
I20260812 06:19:33.190881  4858 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.088s	user 0.003s	sys 0.000s
I20260812 06:19:33.191603  4858 tablet_server.cc:179] TabletServer@127.4.190.129:0 shutting down...
I20260812 06:19:33.282647  5028 maintenance_manager.cc:643] P cd87b83c69e945748493d323b1ab369d: MajorDeltaCompactionOp(a510b20ce2cb460eb59ce4b456ef8bd9) complete. Timing: real 0.158s	user 0.109s	sys 0.047s Metrics: {"cfile_cache_hit":274,"cfile_cache_hit_bytes":11202684,"cfile_cache_miss":358,"cfile_cache_miss_bytes":17674418,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1031,"lbm_read_time_us":8721,"lbm_reads_lt_1ms":390,"lbm_write_time_us":31482,"lbm_writes_lt_1ms":643,"mutex_wait_us":94,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":139648,"update_count":3000}
I20260812 06:19:33.283478  4858 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:33.283937  4858 tablet_replica.cc:333] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d: stopping tablet replica
I20260812 06:19:33.284201  4858 raft_consensus.cc:2243] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:33.284461  4858 raft_consensus.cc:2272] T a510b20ce2cb460eb59ce4b456ef8bd9 P cd87b83c69e945748493d323b1ab369d [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:33.300053  4858 tablet_server.cc:196] TabletServer@127.4.190.129:0 shutdown complete.
I20260812 06:19:33.334651  4858 master.cc:562] Master@127.4.190.190:42977 shutting down...
I20260812 06:19:33.338865  4858 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 01a6015d22d94a07b4097aa3f5587f75 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:33.339068  4858 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 01a6015d22d94a07b4097aa3f5587f75 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:33.339151  4858 tablet_replica.cc:333] T 00000000000000000000000000000000 P 01a6015d22d94a07b4097aa3f5587f75: stopping tablet replica
I20260812 06:19:33.351624  4858 master.cc:584] Master@127.4.190.190:42977 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5677 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:33.460603  4858 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.4.190.190:35267
I20260812 06:19:33.461009  4858 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:33.463333  5175 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:33.463382  4858 server_base.cc:1061] running on GCE node
W20260812 06:19:33.463389  5172 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:33.463537  5173 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:33.463987  4858 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:33.464035  4858 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:33.464051  4858 hybrid_clock.cc:648] HybridClock initialized: now 1786515573464050 us; error 0 us; skew 500 ppm
I20260812 06:19:33.464972  4858 webserver.cc:533] Webserver started at http://127.4.190.190:40019/ using document root <none> and password file <none>
I20260812 06:19:33.465152  4858 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:33.465209  4858 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:33.465314  4858 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:33.465739  4858 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567759193-4858-0/minicluster-data/master-0-root/instance:
uuid: "4e1c9e4c336541b6a9025d0e8cfb3f4c"
format_stamp: "Formatted at 2026-08-12 06:19:33 on dist-test-slave-7kzw"
I20260812 06:19:33.467374  4858 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:19:33.468381  5185 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:33.468631  4858 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:33.468724  4858 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567759193-4858-0/minicluster-data/master-0-root
uuid: "4e1c9e4c336541b6a9025d0e8cfb3f4c"
format_stamp: "Formatted at 2026-08-12 06:19:33 on dist-test-slave-7kzw"
I20260812 06:19:33.468829  4858 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567759193-4858-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567759193-4858-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567759193-4858-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:33.479586  4858 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:33.479995  4858 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:33.485144  4858 rpc_server.cc:307] RPC server started. Bound to: 127.4.190.190:35267
I20260812 06:19:33.490979  5259 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.4.190.190:35267 every 8 connection(s)
I20260812 06:19:33.491515  5261 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:33.493391  5261 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 4e1c9e4c336541b6a9025d0e8cfb3f4c: Bootstrap starting.
I20260812 06:19:33.494208  5261 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 4e1c9e4c336541b6a9025d0e8cfb3f4c: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:33.495242  5261 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 4e1c9e4c336541b6a9025d0e8cfb3f4c: No bootstrap required, opened a new log
I20260812 06:19:33.495697  5261 raft_consensus.cc:359] T 00000000000000000000000000000000 P 4e1c9e4c336541b6a9025d0e8cfb3f4c [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4e1c9e4c336541b6a9025d0e8cfb3f4c" member_type: VOTER }
I20260812 06:19:33.495784  5261 raft_consensus.cc:385] T 00000000000000000000000000000000 P 4e1c9e4c336541b6a9025d0e8cfb3f4c [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:33.495848  5261 raft_consensus.cc:740] T 00000000000000000000000000000000 P 4e1c9e4c336541b6a9025d0e8cfb3f4c [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 4e1c9e4c336541b6a9025d0e8cfb3f4c, State: Initialized, Role: FOLLOWER
I20260812 06:19:33.496029  5261 consensus_queue.cc:260] T 00000000000000000000000000000000 P 4e1c9e4c336541b6a9025d0e8cfb3f4c [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: "4e1c9e4c336541b6a9025d0e8cfb3f4c" member_type: VOTER }
I20260812 06:19:33.496122  5261 raft_consensus.cc:399] T 00000000000000000000000000000000 P 4e1c9e4c336541b6a9025d0e8cfb3f4c [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:33.496191  5261 raft_consensus.cc:493] T 00000000000000000000000000000000 P 4e1c9e4c336541b6a9025d0e8cfb3f4c [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:33.496253  5261 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 4e1c9e4c336541b6a9025d0e8cfb3f4c [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:33.496913  5261 raft_consensus.cc:515] T 00000000000000000000000000000000 P 4e1c9e4c336541b6a9025d0e8cfb3f4c [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4e1c9e4c336541b6a9025d0e8cfb3f4c" member_type: VOTER }
I20260812 06:19:33.497064  5261 leader_election.cc:304] T 00000000000000000000000000000000 P 4e1c9e4c336541b6a9025d0e8cfb3f4c [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: 4e1c9e4c336541b6a9025d0e8cfb3f4c; no voters: 
I20260812 06:19:33.497272  5261 leader_election.cc:290] T 00000000000000000000000000000000 P 4e1c9e4c336541b6a9025d0e8cfb3f4c [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:33.497390  5264 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 4e1c9e4c336541b6a9025d0e8cfb3f4c [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:33.497653  5264 raft_consensus.cc:697] T 00000000000000000000000000000000 P 4e1c9e4c336541b6a9025d0e8cfb3f4c [term 1 LEADER]: Becoming Leader. State: Replica: 4e1c9e4c336541b6a9025d0e8cfb3f4c, State: Running, Role: LEADER
I20260812 06:19:33.497776  5261 sys_catalog.cc:565] T 00000000000000000000000000000000 P 4e1c9e4c336541b6a9025d0e8cfb3f4c [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:33.497794  5264 consensus_queue.cc:237] T 00000000000000000000000000000000 P 4e1c9e4c336541b6a9025d0e8cfb3f4c [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: "4e1c9e4c336541b6a9025d0e8cfb3f4c" member_type: VOTER }
I20260812 06:19:33.498301  5265 sys_catalog.cc:455] T 00000000000000000000000000000000 P 4e1c9e4c336541b6a9025d0e8cfb3f4c [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "4e1c9e4c336541b6a9025d0e8cfb3f4c" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4e1c9e4c336541b6a9025d0e8cfb3f4c" member_type: VOTER } }
I20260812 06:19:33.498327  5266 sys_catalog.cc:455] T 00000000000000000000000000000000 P 4e1c9e4c336541b6a9025d0e8cfb3f4c [sys.catalog]: SysCatalogTable state changed. Reason: New leader 4e1c9e4c336541b6a9025d0e8cfb3f4c. Latest consensus state: current_term: 1 leader_uuid: "4e1c9e4c336541b6a9025d0e8cfb3f4c" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4e1c9e4c336541b6a9025d0e8cfb3f4c" member_type: VOTER } }
I20260812 06:19:33.498494  5265 sys_catalog.cc:458] T 00000000000000000000000000000000 P 4e1c9e4c336541b6a9025d0e8cfb3f4c [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:33.498504  5266 sys_catalog.cc:458] T 00000000000000000000000000000000 P 4e1c9e4c336541b6a9025d0e8cfb3f4c [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:33.499522  5274 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:33.499785  4858 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:33.500309  5274 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:33.502070  5274 catalog_manager.cc:1383] Generated new cluster ID: 50a91afaf33d4c56b62d027f83ef3060
I20260812 06:19:33.502131  5274 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:33.524755  5274 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:33.525395  5274 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:33.535323  5274 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 4e1c9e4c336541b6a9025d0e8cfb3f4c: Generated new TSK 0
I20260812 06:19:33.535535  5274 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:33.564453  4858 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:33.566686  5292 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:33.566672  5297 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:33.566672  5293 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:33.567070  4858 server_base.cc:1061] running on GCE node
I20260812 06:19:33.567262  4858 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:33.567322  4858 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:33.567368  4858 hybrid_clock.cc:648] HybridClock initialized: now 1786515573567367 us; error 0 us; skew 500 ppm
I20260812 06:19:33.568295  4858 webserver.cc:533] Webserver started at http://127.4.190.129:44409/ using document root <none> and password file <none>
I20260812 06:19:33.568486  4858 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:33.568540  4858 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:33.568614  4858 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:33.569022  4858 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567759193-4858-0/minicluster-data/ts-0-root/instance:
uuid: "1fe59a3f3c5749a4a546443c1721ec4a"
format_stamp: "Formatted at 2026-08-12 06:19:33 on dist-test-slave-7kzw"
I20260812 06:19:33.570645  4858 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:33.571717  5306 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:33.572016  4858 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:33.572083  4858 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567759193-4858-0/minicluster-data/ts-0-root
uuid: "1fe59a3f3c5749a4a546443c1721ec4a"
format_stamp: "Formatted at 2026-08-12 06:19:33 on dist-test-slave-7kzw"
I20260812 06:19:33.572176  4858 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567759193-4858-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567759193-4858-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567759193-4858-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:33.582450  4858 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:33.582865  4858 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:33.583160  4858 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:33.583614  4858 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:33.583654  4858 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:33.583686  4858 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:33.583702  4858 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:33.588063  4858 rpc_server.cc:307] RPC server started. Bound to: 127.4.190.129:34989
I20260812 06:19:33.588101  5413 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.4.190.129:34989 every 8 connection(s)
I20260812 06:19:33.596726  5414 heartbeater.cc:344] Connected to a master server at 127.4.190.190:35267
I20260812 06:19:33.596859  5414 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:33.597110  5414 heartbeater.cc:507] Master 127.4.190.190:35267 requested a full tablet report, sending...
I20260812 06:19:33.597781  5210 ts_manager.cc:194] Registered new tserver with Master: 1fe59a3f3c5749a4a546443c1721ec4a (127.4.190.129:34989)
I20260812 06:19:33.598429  4858 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.009917384s
I20260812 06:19:33.598621  5210 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:60890
I20260812 06:19:33.605584  5210 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:60902:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:33.614763  5354 tablet_service.cc:1511] Processing CreateTablet for tablet 8afb113d03cc4c31ac82b5bacdfd2216 (DEFAULT_TABLE table=heavy-update-compaction-test [id=831e2321508b439cb1f5411f9823eae6]), partition=
I20260812 06:19:33.615067  5354 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 8afb113d03cc4c31ac82b5bacdfd2216. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:33.617137  5431 tablet_bootstrap.cc:492] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a: Bootstrap starting.
I20260812 06:19:33.618014  5431 tablet_bootstrap.cc:654] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:33.619114  5431 tablet_bootstrap.cc:492] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a: No bootstrap required, opened a new log
I20260812 06:19:33.619189  5431 ts_tablet_manager.cc:1403] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a: Time spent bootstrapping tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:19:33.619567  5431 raft_consensus.cc:359] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1fe59a3f3c5749a4a546443c1721ec4a" member_type: VOTER last_known_addr { host: "127.4.190.129" port: 34989 } }
I20260812 06:19:33.619686  5431 raft_consensus.cc:385] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:33.619753  5431 raft_consensus.cc:740] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 1fe59a3f3c5749a4a546443c1721ec4a, State: Initialized, Role: FOLLOWER
I20260812 06:19:33.619961  5431 consensus_queue.cc:260] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a [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: "1fe59a3f3c5749a4a546443c1721ec4a" member_type: VOTER last_known_addr { host: "127.4.190.129" port: 34989 } }
I20260812 06:19:33.620076  5431 raft_consensus.cc:399] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:33.620117  5431 raft_consensus.cc:493] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:33.620168  5431 raft_consensus.cc:3060] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:33.620973  5431 raft_consensus.cc:515] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1fe59a3f3c5749a4a546443c1721ec4a" member_type: VOTER last_known_addr { host: "127.4.190.129" port: 34989 } }
I20260812 06:19:33.621091  5431 leader_election.cc:304] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a [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: 1fe59a3f3c5749a4a546443c1721ec4a; no voters: 
I20260812 06:19:33.621240  5431 leader_election.cc:290] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:33.621413  5433 raft_consensus.cc:2804] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:33.621575  5431 ts_tablet_manager.cc:1434] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.003s
I20260812 06:19:33.621622  5433 raft_consensus.cc:697] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a [term 1 LEADER]: Becoming Leader. State: Replica: 1fe59a3f3c5749a4a546443c1721ec4a, State: Running, Role: LEADER
I20260812 06:19:33.621582  5414 heartbeater.cc:499] Master 127.4.190.190:35267 was elected leader, sending a full tablet report...
I20260812 06:19:33.621822  5433 consensus_queue.cc:237] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a [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: "1fe59a3f3c5749a4a546443c1721ec4a" member_type: VOTER last_known_addr { host: "127.4.190.129" port: 34989 } }
I20260812 06:19:33.623234  5210 catalog_manager.cc:5719] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a reported cstate change: term changed from 0 to 1, leader changed from <none> to 1fe59a3f3c5749a4a546443c1721ec4a (127.4.190.129). New cstate: current_term: 1 leader_uuid: "1fe59a3f3c5749a4a546443c1721ec4a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1fe59a3f3c5749a4a546443c1721ec4a" member_type: VOTER last_known_addr { host: "127.4.190.129" port: 34989 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:33.685449  4858 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.055s	user 0.018s	sys 0.004s
I20260812 06:19:33.839082  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling FlushMRSOp(8afb113d03cc4c31ac82b5bacdfd2216): perf score=19.054940
I20260812 06:19:34.000864  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: FlushMRSOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.161s	user 0.131s	sys 0.024s Metrics: {"bytes_written":12717735,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":76,"dirs.run_cpu_time_us":235,"dirs.run_wall_time_us":781,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":39714,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":766,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1550}
I20260812 06:19:34.001658  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling LogGCOp(8afb113d03cc4c31ac82b5bacdfd2216): free 20743880 bytes of WAL
I20260812 06:19:34.001894  5313 log_reader.cc:385] T 8afb113d03cc4c31ac82b5bacdfd2216: removed 2 log segments from log reader
I20260812 06:19:34.001992  5313 log.cc:1079] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/8afb113d03cc4c31ac82b5bacdfd2216/wal-000000001 (ops 1-6)
I20260812 06:19:34.002068  5313 log.cc:1079] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/8afb113d03cc4c31ac82b5bacdfd2216/wal-000000002 (ops 7-11)
I20260812 06:19:34.011304  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: LogGCOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.009s	user 0.000s	sys 0.009s Metrics: {}
I20260812 06:19:34.011781  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling UndoDeltaBlockGCOp(8afb113d03cc4c31ac82b5bacdfd2216): 16411396 bytes on disk
I20260812 06:19:34.012272  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: UndoDeltaBlockGCOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4}
I20260812 06:19:34.012732  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216): perf score=2.188937
I20260812 06:19:34.027877  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.015s	user 0.008s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3854,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:34.028335  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216): perf score=2.188937
I20260812 06:19:34.039677  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4273,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:34.040115  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling MajorDeltaCompactionOp(8afb113d03cc4c31ac82b5bacdfd2216): perf score=1.000000
I20260812 06:19:34.213810  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: MajorDeltaCompactionOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.174s	user 0.118s	sys 0.056s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":604,"lbm_read_time_us":12994,"lbm_reads_lt_1ms":569,"lbm_write_time_us":28268,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2688,"thread_start_us":303,"threads_started":5,"update_count":2500}
I20260812 06:19:34.214376  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216): perf score=14.095187
I20260812 06:19:34.267652  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.053s	user 0.038s	sys 0.013s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22890,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:34.268283  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216): perf score=2.188937
I20260812 06:19:34.284929  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.016s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102660,"delete_count":0,"lbm_write_time_us":6727,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:34.285871  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling MajorDeltaCompactionOp(8afb113d03cc4c31ac82b5bacdfd2216): perf score=1.000000
I20260812 06:19:34.478653  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: MajorDeltaCompactionOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.193s	user 0.118s	sys 0.073s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":399,"lbm_read_time_us":13444,"lbm_reads_lt_1ms":564,"lbm_write_time_us":32325,"lbm_writes_lt_1ms":543,"mutex_wait_us":48,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12928,"update_count":2500}
I20260812 06:19:34.479401  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216): perf score=14.095187
I20260812 06:19:34.541956  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.062s	user 0.019s	sys 0.040s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24012,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:34.542578  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216): perf score=3.181125
I20260812 06:19:34.555073  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.012s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4759047,"delete_count":0,"lbm_write_time_us":4967,"lbm_writes_lt_1ms":119,"reinsert_count":0,"update_count":580}
I20260812 06:19:34.555579  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216): perf score=2.188937
I20260812 06:19:34.564498  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.009s	user 0.004s	sys 0.003s Metrics: {"bytes_written":3446255,"delete_count":0,"lbm_write_time_us":3448,"lbm_writes_lt_1ms":87,"reinsert_count":0,"update_count":420}
I20260812 06:19:34.565016  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling MajorDeltaCompactionOp(8afb113d03cc4c31ac82b5bacdfd2216): perf score=1.000000
I20260812 06:19:34.802549  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: MajorDeltaCompactionOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.237s	user 0.150s	sys 0.083s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877203,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":506,"lbm_read_time_us":15373,"lbm_reads_lt_1ms":673,"lbm_write_time_us":39032,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1152,"update_count":3000}
I20260812 06:19:34.803150  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216): perf score=16.079562
I20260812 06:19:34.876080  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.073s	user 0.039s	sys 0.024s Metrics: {"bytes_written":18461108,"delete_count":0,"lbm_write_time_us":27971,"lbm_writes_lt_1ms":453,"reinsert_count":0,"update_count":2250}
I20260812 06:19:34.876542  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216): perf score=4.173312
I20260812 06:19:34.893436  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.017s	user 0.011s	sys 0.004s Metrics: {"bytes_written":6153873,"delete_count":0,"lbm_write_time_us":6988,"lbm_writes_lt_1ms":153,"reinsert_count":0,"update_count":750}
I20260812 06:19:34.893962  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling MajorDeltaCompactionOp(8afb113d03cc4c31ac82b5bacdfd2216): perf score=1.000000
I20260812 06:19:35.110137  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: MajorDeltaCompactionOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.216s	user 0.138s	sys 0.067s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877103,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":266,"lbm_read_time_us":15218,"lbm_reads_lt_1ms":672,"lbm_write_time_us":36973,"lbm_writes_lt_1ms":643,"mutex_wait_us":54,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7680,"update_count":3000}
I20260812 06:19:35.111083  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216): perf score=18.063937
I20260812 06:19:35.180579  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.069s	user 0.039s	sys 0.016s Metrics: {"bytes_written":20512311,"delete_count":0,"lbm_write_time_us":26041,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:35.181164  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216): perf score=2.188937
I20260812 06:19:35.191677  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.010s	user 0.000s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4048,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:35.192425  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling FlushMRSOp(8afb113d03cc4c31ac82b5bacdfd2216): perf score=1.000000
I20260812 06:19:35.221369  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: FlushMRSOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.029s	user 0.020s	sys 0.006s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":97,"dirs.run_cpu_time_us":260,"dirs.run_wall_time_us":1401,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1413,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:35.222024  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling LogGCOp(8afb113d03cc4c31ac82b5bacdfd2216): free 108535462 bytes of WAL
I20260812 06:19:35.222299  5313 log_reader.cc:385] T 8afb113d03cc4c31ac82b5bacdfd2216: removed 11 log segments from log reader
I20260812 06:19:35.222373  5313 log.cc:1079] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/8afb113d03cc4c31ac82b5bacdfd2216/wal-000000003 (ops 12-16)
I20260812 06:19:35.222425  5313 log.cc:1079] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/8afb113d03cc4c31ac82b5bacdfd2216/wal-000000004 (ops 17-21)
I20260812 06:19:35.222504  5313 log.cc:1079] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/8afb113d03cc4c31ac82b5bacdfd2216/wal-000000005 (ops 22-26)
I20260812 06:19:35.222558  5313 log.cc:1079] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/8afb113d03cc4c31ac82b5bacdfd2216/wal-000000006 (ops 27-30)
I20260812 06:19:35.222596  5313 log.cc:1079] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/8afb113d03cc4c31ac82b5bacdfd2216/wal-000000007 (ops 31-35)
I20260812 06:19:35.222635  5313 log.cc:1079] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/8afb113d03cc4c31ac82b5bacdfd2216/wal-000000008 (ops 36-40)
I20260812 06:19:35.222674  5313 log.cc:1079] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/8afb113d03cc4c31ac82b5bacdfd2216/wal-000000009 (ops 41-44)
I20260812 06:19:35.222713  5313 log.cc:1079] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/8afb113d03cc4c31ac82b5bacdfd2216/wal-000000010 (ops 45-49)
I20260812 06:19:35.222751  5313 log.cc:1079] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/8afb113d03cc4c31ac82b5bacdfd2216/wal-000000011 (ops 50-54)
I20260812 06:19:35.222790  5313 log.cc:1079] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/8afb113d03cc4c31ac82b5bacdfd2216/wal-000000012 (ops 55-59)
I20260812 06:19:35.222828  5313 log.cc:1079] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/8afb113d03cc4c31ac82b5bacdfd2216/wal-000000013 (ops 60-64)
I20260812 06:19:35.246019  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: LogGCOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.024s	user 0.005s	sys 0.015s Metrics: {}
I20260812 06:19:35.246531  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216): perf score=2.188937
I20260812 06:19:35.263512  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.017s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4920,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:35.263957  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling LogGCOp(8afb113d03cc4c31ac82b5bacdfd2216): free 11564875 bytes of WAL
I20260812 06:19:35.264170  5313 log_reader.cc:385] T 8afb113d03cc4c31ac82b5bacdfd2216: removed 1 log segments from log reader
I20260812 06:19:35.264230  5313 log.cc:1079] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/8afb113d03cc4c31ac82b5bacdfd2216/wal-000000014 (ops 65-68)
I20260812 06:19:35.266604  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: LogGCOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.002s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:19:35.266891  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling UndoDeltaBlockGCOp(8afb113d03cc4c31ac82b5bacdfd2216): 447 bytes on disk
I20260812 06:19:35.267295  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: UndoDeltaBlockGCOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:19:35.267712  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216): perf score=2.188937
I20260812 06:19:35.280313  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.012s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4611,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:35.280767  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling MajorDeltaCompactionOp(8afb113d03cc4c31ac82b5bacdfd2216): perf score=1.000000
I20260812 06:19:35.552256  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: MajorDeltaCompactionOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.271s	user 0.187s	sys 0.071s Metrics: {"cfile_cache_miss":834,"cfile_cache_miss_bytes":37082159,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":978,"lbm_read_time_us":19042,"lbm_reads_lt_1ms":866,"lbm_write_time_us":48043,"lbm_writes_lt_1ms":843,"mutex_wait_us":330,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":26368,"thread_start_us":82,"threads_started":1,"update_count":4000}
I20260812 06:19:35.553260  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216): perf score=22.032687
I20260812 06:19:35.622825  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.069s	user 0.049s	sys 0.020s Metrics: {"bytes_written":24614720,"delete_count":0,"lbm_write_time_us":31532,"lbm_writes_lt_1ms":603,"reinsert_count":0,"update_count":3000}
I20260812 06:19:35.623430  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216): perf score=2.188937
I20260812 06:19:35.644906  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.021s	user 0.005s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7632,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:35.645385  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling MajorDeltaCompactionOp(8afb113d03cc4c31ac82b5bacdfd2216): perf score=1.000000
I20260812 06:19:35.855219  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: MajorDeltaCompactionOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.210s	user 0.138s	sys 0.060s Metrics: {"cfile_cache_miss":732,"cfile_cache_miss_bytes":32979507,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1101,"lbm_read_time_us":16468,"lbm_reads_lt_1ms":764,"lbm_write_time_us":41772,"lbm_writes_lt_1ms":743,"mutex_wait_us":86,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":31616,"update_count":3500}
I20260812 06:19:35.856042  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216): perf score=18.063937
I20260812 06:19:35.921662  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.065s	user 0.038s	sys 0.024s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":29635,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:35.922132  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216): perf score=3.181125
I20260812 06:19:35.944350  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.022s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":6273,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:35.944834  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216): perf score=2.188937
I20260812 06:19:35.954661  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.010s	user 0.002s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3755,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:35.955127  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling MajorDeltaCompactionOp(8afb113d03cc4c31ac82b5bacdfd2216): perf score=1.000000
I20260812 06:19:36.148813  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: MajorDeltaCompactionOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.193s	user 0.153s	sys 0.040s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32979620,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":266,"lbm_read_time_us":14390,"lbm_reads_lt_1ms":773,"lbm_write_time_us":40569,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":3712,"update_count":3500}
I20260812 06:19:36.150027  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216): perf score=14.095187
I20260812 06:19:36.191414  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.041s	user 0.037s	sys 0.003s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18489,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:36.191941  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216): perf score=2.188937
I20260812 06:19:36.204483  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4320,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:36.205132  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling MajorDeltaCompactionOp(8afb113d03cc4c31ac82b5bacdfd2216): perf score=1.000000
I20260812 06:19:36.368717  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: MajorDeltaCompactionOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.163s	user 0.117s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":234,"lbm_read_time_us":10085,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29758,"lbm_writes_lt_1ms":543,"mutex_wait_us":111,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9088,"update_count":2500}
I20260812 06:19:36.369297  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216): perf score=14.095187
I20260812 06:19:36.412379  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.043s	user 0.026s	sys 0.015s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":18616,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:36.413048  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling MajorDeltaCompactionOp(8afb113d03cc4c31ac82b5bacdfd2216): perf score=1.000000
I20260812 06:19:36.568019  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: MajorDeltaCompactionOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.155s	user 0.099s	sys 0.054s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672160,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":448,"lbm_read_time_us":10396,"lbm_reads_lt_1ms":467,"lbm_write_time_us":27283,"lbm_writes_lt_1ms":443,"mutex_wait_us":96,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3584,"update_count":2000}
I20260812 06:19:36.568738  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216): perf score=11.118625
I20260812 06:19:36.608906  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.040s	user 0.013s	sys 0.025s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":17057,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:36.609460  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216): perf score=2.188937
I20260812 06:19:36.621277  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.012s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4119,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:36.621896  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling FlushMRSOp(8afb113d03cc4c31ac82b5bacdfd2216): perf score=1.000000
I20260812 06:19:36.675239  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: FlushMRSOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.053s	user 0.035s	sys 0.001s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":61,"dirs.run_cpu_time_us":268,"dirs.run_wall_time_us":1355,"drs_written":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2549,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:36.676273  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216): perf score=6.157687
I20260812 06:19:36.699828  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.023s	user 0.009s	sys 0.013s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":9502,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:36.700383  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling LogGCOp(8afb113d03cc4c31ac82b5bacdfd2216): free 121006381 bytes of WAL
I20260812 06:19:36.700726  5313 log_reader.cc:385] T 8afb113d03cc4c31ac82b5bacdfd2216: removed 12 log segments from log reader
I20260812 06:19:36.700802  5313 log.cc:1079] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/8afb113d03cc4c31ac82b5bacdfd2216/wal-000000015 (ops 69-73)
I20260812 06:19:36.700860  5313 log.cc:1079] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/8afb113d03cc4c31ac82b5bacdfd2216/wal-000000016 (ops 74-78)
I20260812 06:19:36.700896  5313 log.cc:1079] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/8afb113d03cc4c31ac82b5bacdfd2216/wal-000000017 (ops 79-83)
I20260812 06:19:36.700935  5313 log.cc:1079] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/8afb113d03cc4c31ac82b5bacdfd2216/wal-000000018 (ops 84-88)
I20260812 06:19:36.700970  5313 log.cc:1079] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/8afb113d03cc4c31ac82b5bacdfd2216/wal-000000019 (ops 89-93)
I20260812 06:19:36.701007  5313 log.cc:1079] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/8afb113d03cc4c31ac82b5bacdfd2216/wal-000000020 (ops 94-98)
I20260812 06:19:36.701045  5313 log.cc:1079] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/8afb113d03cc4c31ac82b5bacdfd2216/wal-000000021 (ops 99-102)
I20260812 06:19:36.701081  5313 log.cc:1079] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/8afb113d03cc4c31ac82b5bacdfd2216/wal-000000022 (ops 103-107)
I20260812 06:19:36.701118  5313 log.cc:1079] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/8afb113d03cc4c31ac82b5bacdfd2216/wal-000000023 (ops 108-112)
I20260812 06:19:36.701165  5313 log.cc:1079] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/8afb113d03cc4c31ac82b5bacdfd2216/wal-000000024 (ops 113-117)
I20260812 06:19:36.701202  5313 log.cc:1079] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/8afb113d03cc4c31ac82b5bacdfd2216/wal-000000025 (ops 118-122)
I20260812 06:19:36.701241  5313 log.cc:1079] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/8afb113d03cc4c31ac82b5bacdfd2216/wal-000000026 (ops 123-127)
I20260812 06:19:36.728498  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: LogGCOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.028s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:36.728922  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216): perf score=2.188937
I20260812 06:19:36.739799  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4264,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:36.740449  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling UndoDeltaBlockGCOp(8afb113d03cc4c31ac82b5bacdfd2216): 473 bytes on disk
I20260812 06:19:36.741096  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: UndoDeltaBlockGCOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":120,"lbm_reads_lt_1ms":4}
I20260812 06:19:36.741834  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling MajorDeltaCompactionOp(8afb113d03cc4c31ac82b5bacdfd2216): perf score=1.000000
I20260812 06:19:36.992558  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: MajorDeltaCompactionOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.250s	user 0.153s	sys 0.096s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979744,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":201,"lbm_read_time_us":17240,"lbm_reads_lt_1ms":770,"lbm_write_time_us":42931,"lbm_writes_lt_1ms":743,"mutex_wait_us":41,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":14720,"thread_start_us":79,"threads_started":1,"update_count":3500}
I20260812 06:19:36.995123  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216): perf score=18.063937
I20260812 06:19:37.066356  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.071s	user 0.037s	sys 0.016s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":25887,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:37.066924  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216): perf score=2.188937
I20260812 06:19:37.078572  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.011s	user 0.008s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4033,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:37.079080  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling MajorDeltaCompactionOp(8afb113d03cc4c31ac82b5bacdfd2216): perf score=1.000000
I20260812 06:19:37.288142  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: MajorDeltaCompactionOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.209s	user 0.129s	sys 0.076s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":884,"lbm_read_time_us":14289,"lbm_reads_lt_1ms":672,"lbm_write_time_us":35007,"lbm_writes_lt_1ms":643,"mutex_wait_us":355,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":3000}
I20260812 06:19:37.288976  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216): perf score=15.087375
I20260812 06:19:37.363394  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.074s	user 0.039s	sys 0.020s Metrics: {"bytes_written":17558579,"delete_count":0,"lbm_write_time_us":26670,"lbm_writes_lt_1ms":431,"reinsert_count":0,"update_count":2140}
I20260812 06:19:37.363989  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216): perf score=5.165500
I20260812 06:19:37.393627  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.029s	user 0.013s	sys 0.013s Metrics: {"bytes_written":7056405,"delete_count":0,"lbm_write_time_us":10811,"lbm_writes_lt_1ms":175,"reinsert_count":0,"update_count":860}
I20260812 06:19:37.394239  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling MajorDeltaCompactionOp(8afb113d03cc4c31ac82b5bacdfd2216): perf score=1.000000
I20260812 06:19:37.593508  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: MajorDeltaCompactionOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.199s	user 0.130s	sys 0.067s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877106,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":371,"lbm_read_time_us":12730,"lbm_reads_lt_1ms":664,"lbm_write_time_us":35629,"lbm_writes_lt_1ms":643,"mutex_wait_us":24,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":23424,"update_count":3000}
I20260812 06:19:37.594360  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216): perf score=14.095187
I20260812 06:19:37.656347  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.062s	user 0.050s	sys 0.000s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23150,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:37.657048  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216): perf score=2.188937
I20260812 06:19:37.673275  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.016s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5992,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:37.673775  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling MajorDeltaCompactionOp(8afb113d03cc4c31ac82b5bacdfd2216): perf score=1.000000
I20260812 06:19:37.870326  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: MajorDeltaCompactionOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.196s	user 0.147s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":376,"lbm_read_time_us":12912,"lbm_reads_lt_1ms":568,"lbm_write_time_us":35491,"lbm_writes_lt_1ms":543,"mutex_wait_us":46,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12416,"update_count":2500}
I20260812 06:19:37.873050  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216): perf score=14.095187
I20260812 06:19:37.933594  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.060s	user 0.043s	sys 0.004s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21032,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:37.934230  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216): perf score=2.188937
I20260812 06:19:37.946764  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.012s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4521,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:37.947495  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling MajorDeltaCompactionOp(8afb113d03cc4c31ac82b5bacdfd2216): perf score=1.000000
I20260812 06:19:38.123301  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: MajorDeltaCompactionOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.174s	user 0.115s	sys 0.059s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":704,"lbm_read_time_us":13524,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30543,"lbm_writes_lt_1ms":543,"mutex_wait_us":40,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":27008,"update_count":2500}
I20260812 06:19:38.124080  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216): perf score=14.095187
I20260812 06:19:38.183027  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.059s	user 0.031s	sys 0.027s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21114,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:38.183705  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216): perf score=2.188937
I20260812 06:19:38.198421  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5930,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:38.199018  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling FlushMRSOp(8afb113d03cc4c31ac82b5bacdfd2216): perf score=1.000000
I20260812 06:19:38.230784  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: FlushMRSOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.032s	user 0.024s	sys 0.004s Metrics: {"bytes_written":1193505,"cfile_init":1,"dirs.queue_time_us":81,"dirs.run_cpu_time_us":282,"dirs.run_wall_time_us":1284,"drs_written":1,"lbm_read_time_us":35,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1550,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:38.231529  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling MajorDeltaCompactionOp(8afb113d03cc4c31ac82b5bacdfd2216): perf score=1.000000
I20260812 06:19:38.424156  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: MajorDeltaCompactionOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.192s	user 0.116s	sys 0.076s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":646,"lbm_read_time_us":13917,"lbm_reads_lt_1ms":564,"lbm_write_time_us":32705,"lbm_writes_lt_1ms":543,"mutex_wait_us":332,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11008,"update_count":2500}
I20260812 06:19:38.424937  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling LogGCOp(8afb113d03cc4c31ac82b5bacdfd2216): free 120100636 bytes of WAL
I20260812 06:19:38.425202  5313 log_reader.cc:385] T 8afb113d03cc4c31ac82b5bacdfd2216: removed 12 log segments from log reader
I20260812 06:19:38.425256  5313 log.cc:1079] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/8afb113d03cc4c31ac82b5bacdfd2216/wal-000000027 (ops 128-132)
I20260812 06:19:38.425302  5313 log.cc:1079] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/8afb113d03cc4c31ac82b5bacdfd2216/wal-000000028 (ops 133-137)
I20260812 06:19:38.425349  5313 log.cc:1079] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/8afb113d03cc4c31ac82b5bacdfd2216/wal-000000029 (ops 138-142)
I20260812 06:19:38.425392  5313 log.cc:1079] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/8afb113d03cc4c31ac82b5bacdfd2216/wal-000000030 (ops 143-146)
I20260812 06:19:38.425436  5313 log.cc:1079] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/8afb113d03cc4c31ac82b5bacdfd2216/wal-000000031 (ops 147-151)
I20260812 06:19:38.425480  5313 log.cc:1079] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/8afb113d03cc4c31ac82b5bacdfd2216/wal-000000032 (ops 152-156)
I20260812 06:19:38.425570  5313 log.cc:1079] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/8afb113d03cc4c31ac82b5bacdfd2216/wal-000000033 (ops 157-161)
I20260812 06:19:38.425619  5313 log.cc:1079] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/8afb113d03cc4c31ac82b5bacdfd2216/wal-000000034 (ops 162-166)
I20260812 06:19:38.425699  5313 log.cc:1079] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/8afb113d03cc4c31ac82b5bacdfd2216/wal-000000035 (ops 167-170)
I20260812 06:19:38.425745  5313 log.cc:1079] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/8afb113d03cc4c31ac82b5bacdfd2216/wal-000000036 (ops 171-175)
I20260812 06:19:38.425800  5313 log.cc:1079] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/8afb113d03cc4c31ac82b5bacdfd2216/wal-000000037 (ops 176-180)
I20260812 06:19:38.425844  5313 log.cc:1079] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a: Deleting log segment in path: /tmp/dist-test-tasknrLGWu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515567759193-4858-0/minicluster-data/ts-0-root/wals/8afb113d03cc4c31ac82b5bacdfd2216/wal-000000038 (ops 181-184)
I20260812 06:19:38.456918  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: LogGCOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.032s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:19:38.457768  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216): perf score=17.071750
I20260812 06:19:38.527177  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.069s	user 0.036s	sys 0.032s Metrics: {"bytes_written":19896955,"delete_count":0,"lbm_write_time_us":27798,"lbm_writes_lt_1ms":488,"reinsert_count":0,"update_count":2425}
I20260812 06:19:38.527742  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling UndoDeltaBlockGCOp(8afb113d03cc4c31ac82b5bacdfd2216): 462 bytes on disk
I20260812 06:19:38.528169  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: UndoDeltaBlockGCOp(8afb113d03cc4c31ac82b5bacdfd2216) 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:19:38.528685  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216): perf score=3.181125
I20260812 06:19:38.541177  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4718026,"delete_count":0,"lbm_write_time_us":4695,"lbm_writes_lt_1ms":118,"reinsert_count":0,"update_count":575}
I20260812 06:19:38.541863  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling MajorDeltaCompactionOp(8afb113d03cc4c31ac82b5bacdfd2216): perf score=1.000000
I20260812 06:19:38.683519  4858 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.998s	user 1.860s	sys 0.146s
I20260812 06:19:38.730355  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: MajorDeltaCompactionOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.188s	user 0.111s	sys 0.075s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877109,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"lbm_read_time_us":15746,"lbm_reads_lt_1ms":668,"lbm_write_time_us":32532,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:19:38.730914  5415 maintenance_manager.cc:419] P 1fe59a3f3c5749a4a546443c1721ec4a: Scheduling FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216): perf score=10.126437
I20260812 06:19:38.753728  4858 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.070s	user 0.001s	sys 0.000s
I20260812 06:19:38.754325  4858 tablet_server.cc:179] TabletServer@127.4.190.129:0 shutting down...
I20260812 06:19:38.767467  5313 maintenance_manager.cc:643] P 1fe59a3f3c5749a4a546443c1721ec4a: FlushDeltaMemStoresOp(8afb113d03cc4c31ac82b5bacdfd2216) complete. Timing: real 0.036s	user 0.019s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16397,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:38.767987  4858 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:38.768321  4858 tablet_replica.cc:333] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a: stopping tablet replica
I20260812 06:19:38.768510  4858 raft_consensus.cc:2243] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:38.778429  4858 raft_consensus.cc:2272] T 8afb113d03cc4c31ac82b5bacdfd2216 P 1fe59a3f3c5749a4a546443c1721ec4a [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:38.782352  4858 tablet_server.cc:196] TabletServer@127.4.190.129:0 shutdown complete.
I20260812 06:19:38.789959  4858 master.cc:562] Master@127.4.190.190:35267 shutting down...
I20260812 06:19:38.793671  4858 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 4e1c9e4c336541b6a9025d0e8cfb3f4c [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:38.793830  4858 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 4e1c9e4c336541b6a9025d0e8cfb3f4c [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:38.793880  4858 tablet_replica.cc:333] T 00000000000000000000000000000000 P 4e1c9e4c336541b6a9025d0e8cfb3f4c: stopping tablet replica
I20260812 06:19:38.806295  4858 master.cc:584] Master@127.4.190.190:35267 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5455 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11134 ms total)

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