[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:20:19.556979 12543 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.12.63.254:39967
I20260812 06:20:19.558017 12543 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:20:19.558636 12543 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:19.565627 12551 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:19.565802 12549 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:19.565797 12548 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:19.565865 12543 server_base.cc:1061] running on GCE node
I20260812 06:20:19.566538 12543 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:19.566671 12543 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:19.566732 12543 hybrid_clock.cc:648] HybridClock initialized: now 1786515619566729 us; error 0 us; skew 500 ppm
I20260812 06:20:19.568681 12543 webserver.cc:533] Webserver started at http://127.12.63.254:34981/ using document root <none> and password file <none>
I20260812 06:20:19.569262 12543 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:19.569355 12543 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:19.569618 12543 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:19.571424 12543 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619545971-12543-0/minicluster-data/master-0-root/instance:
uuid: "47495066a2644665a198c62b4f5f98e4"
format_stamp: "Formatted at 2026-08-12 06:20:19 on dist-test-slave-wl2h"
I20260812 06:20:19.575083 12543 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:20:19.577201 12557 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:19.578233 12543 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:19.578372 12543 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619545971-12543-0/minicluster-data/master-0-root
uuid: "47495066a2644665a198c62b4f5f98e4"
format_stamp: "Formatted at 2026-08-12 06:20:19 on dist-test-slave-wl2h"
I20260812 06:20:19.578491 12543 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619545971-12543-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619545971-12543-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619545971-12543-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:19.605873 12543 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:19.606638 12543 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:20:19.606838 12543 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:19.614876 12543 rpc_server.cc:307] RPC server started. Bound to: 127.12.63.254:39967
I20260812 06:20:19.615041 12621 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.12.63.254:39967 every 8 connection(s)
I20260812 06:20:19.617332 12622 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:19.622879 12622 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 47495066a2644665a198c62b4f5f98e4: Bootstrap starting.
I20260812 06:20:19.625304 12622 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 47495066a2644665a198c62b4f5f98e4: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:19.626194 12622 log.cc:826] T 00000000000000000000000000000000 P 47495066a2644665a198c62b4f5f98e4: Log is configured to *not* fsync() on all Append() calls
I20260812 06:20:19.627954 12622 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 47495066a2644665a198c62b4f5f98e4: No bootstrap required, opened a new log
I20260812 06:20:19.630775 12622 raft_consensus.cc:359] T 00000000000000000000000000000000 P 47495066a2644665a198c62b4f5f98e4 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "47495066a2644665a198c62b4f5f98e4" member_type: VOTER }
I20260812 06:20:19.630950 12622 raft_consensus.cc:385] T 00000000000000000000000000000000 P 47495066a2644665a198c62b4f5f98e4 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:19.630991 12622 raft_consensus.cc:740] T 00000000000000000000000000000000 P 47495066a2644665a198c62b4f5f98e4 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 47495066a2644665a198c62b4f5f98e4, State: Initialized, Role: FOLLOWER
I20260812 06:20:19.631690 12622 consensus_queue.cc:260] T 00000000000000000000000000000000 P 47495066a2644665a198c62b4f5f98e4 [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: "47495066a2644665a198c62b4f5f98e4" member_type: VOTER }
I20260812 06:20:19.631846 12622 raft_consensus.cc:399] T 00000000000000000000000000000000 P 47495066a2644665a198c62b4f5f98e4 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:19.631896 12622 raft_consensus.cc:493] T 00000000000000000000000000000000 P 47495066a2644665a198c62b4f5f98e4 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:19.631979 12622 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 47495066a2644665a198c62b4f5f98e4 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:19.632776 12622 raft_consensus.cc:515] T 00000000000000000000000000000000 P 47495066a2644665a198c62b4f5f98e4 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "47495066a2644665a198c62b4f5f98e4" member_type: VOTER }
I20260812 06:20:19.633162 12622 leader_election.cc:304] T 00000000000000000000000000000000 P 47495066a2644665a198c62b4f5f98e4 [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: 47495066a2644665a198c62b4f5f98e4; no voters: 
I20260812 06:20:19.633448 12622 leader_election.cc:290] T 00000000000000000000000000000000 P 47495066a2644665a198c62b4f5f98e4 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:19.633598 12626 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 47495066a2644665a198c62b4f5f98e4 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:19.633894 12626 raft_consensus.cc:697] T 00000000000000000000000000000000 P 47495066a2644665a198c62b4f5f98e4 [term 1 LEADER]: Becoming Leader. State: Replica: 47495066a2644665a198c62b4f5f98e4, State: Running, Role: LEADER
I20260812 06:20:19.634294 12626 consensus_queue.cc:237] T 00000000000000000000000000000000 P 47495066a2644665a198c62b4f5f98e4 [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: "47495066a2644665a198c62b4f5f98e4" member_type: VOTER }
I20260812 06:20:19.634555 12622 sys_catalog.cc:565] T 00000000000000000000000000000000 P 47495066a2644665a198c62b4f5f98e4 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:19.636216 12627 sys_catalog.cc:455] T 00000000000000000000000000000000 P 47495066a2644665a198c62b4f5f98e4 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "47495066a2644665a198c62b4f5f98e4" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "47495066a2644665a198c62b4f5f98e4" member_type: VOTER } }
I20260812 06:20:19.636283 12629 sys_catalog.cc:455] T 00000000000000000000000000000000 P 47495066a2644665a198c62b4f5f98e4 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 47495066a2644665a198c62b4f5f98e4. Latest consensus state: current_term: 1 leader_uuid: "47495066a2644665a198c62b4f5f98e4" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "47495066a2644665a198c62b4f5f98e4" member_type: VOTER } }
I20260812 06:20:19.636343 12627 sys_catalog.cc:458] T 00000000000000000000000000000000 P 47495066a2644665a198c62b4f5f98e4 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:19.636373 12629 sys_catalog.cc:458] T 00000000000000000000000000000000 P 47495066a2644665a198c62b4f5f98e4 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:19.636682 12639 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:19.639339 12639 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:19.639631 12543 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:19.644810 12639 catalog_manager.cc:1383] Generated new cluster ID: 1099f643e2f949c89e62da1bc3f1a53b
I20260812 06:20:19.644893 12639 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:19.655398 12639 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:19.656584 12639 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:19.665787 12639 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 47495066a2644665a198c62b4f5f98e4: Generated new TSK 0
I20260812 06:20:19.666603 12639 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:19.672333 12543 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:19.675344 12653 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:19.675364 12656 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:19.675400 12652 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:19.676041 12543 server_base.cc:1061] running on GCE node
I20260812 06:20:19.676226 12543 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:19.676285 12543 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:19.676311 12543 hybrid_clock.cc:648] HybridClock initialized: now 1786515619676309 us; error 0 us; skew 500 ppm
I20260812 06:20:19.677238 12543 webserver.cc:533] Webserver started at http://127.12.63.193:45043/ using document root <none> and password file <none>
I20260812 06:20:19.677421 12543 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:19.677495 12543 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:19.677588 12543 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:19.677999 12543 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619545971-12543-0/minicluster-data/ts-0-root/instance:
uuid: "780cb545328e4547bf9973256379f5ad"
format_stamp: "Formatted at 2026-08-12 06:20:19 on dist-test-slave-wl2h"
I20260812 06:20:19.679617 12543 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:20:19.680631 12664 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:19.680882 12543 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:19.680955 12543 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619545971-12543-0/minicluster-data/ts-0-root
uuid: "780cb545328e4547bf9973256379f5ad"
format_stamp: "Formatted at 2026-08-12 06:20:19 on dist-test-slave-wl2h"
I20260812 06:20:19.681044 12543 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619545971-12543-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619545971-12543-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619545971-12543-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:19.688834 12543 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:19.689285 12543 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:19.689824 12543 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:19.690649 12543 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:19.690701 12543 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:19.690771 12543 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:19.690809 12543 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:19.698948 12543 rpc_server.cc:307] RPC server started. Bound to: 127.12.63.193:33735
I20260812 06:20:19.698974 12742 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.12.63.193:33735 every 8 connection(s)
I20260812 06:20:19.709463 12744 heartbeater.cc:344] Connected to a master server at 127.12.63.254:39967
I20260812 06:20:19.709743 12744 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:19.710223 12744 heartbeater.cc:507] Master 127.12.63.254:39967 requested a full tablet report, sending...
I20260812 06:20:19.711740 12580 ts_manager.cc:194] Registered new tserver with Master: 780cb545328e4547bf9973256379f5ad (127.12.63.193:33735)
I20260812 06:20:19.712258 12543 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012561611s
I20260812 06:20:19.713116 12580 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:39922
I20260812 06:20:19.723484 12580 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:39924:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:20:19.738631 12703 tablet_service.cc:1511] Processing CreateTablet for tablet 3e99b2a9fc2b46a786467e82fed31e34 (DEFAULT_TABLE table=heavy-update-compaction-test [id=635f7dafd80349f9a687833b3e36d357]), partition=
I20260812 06:20:19.739320 12703 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 3e99b2a9fc2b46a786467e82fed31e34. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:19.741616 12761 tablet_bootstrap.cc:492] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad: Bootstrap starting.
I20260812 06:20:19.742710 12761 tablet_bootstrap.cc:654] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:19.743932 12761 tablet_bootstrap.cc:492] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad: No bootstrap required, opened a new log
I20260812 06:20:19.744046 12761 ts_tablet_manager.cc:1403] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:20:19.744526 12761 raft_consensus.cc:359] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "780cb545328e4547bf9973256379f5ad" member_type: VOTER last_known_addr { host: "127.12.63.193" port: 33735 } }
I20260812 06:20:19.744630 12761 raft_consensus.cc:385] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:19.744653 12761 raft_consensus.cc:740] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 780cb545328e4547bf9973256379f5ad, State: Initialized, Role: FOLLOWER
I20260812 06:20:19.744853 12761 consensus_queue.cc:260] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad [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: "780cb545328e4547bf9973256379f5ad" member_type: VOTER last_known_addr { host: "127.12.63.193" port: 33735 } }
I20260812 06:20:19.744951 12761 raft_consensus.cc:399] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:19.745013 12761 raft_consensus.cc:493] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:19.745071 12761 raft_consensus.cc:3060] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:19.746290 12761 raft_consensus.cc:515] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "780cb545328e4547bf9973256379f5ad" member_type: VOTER last_known_addr { host: "127.12.63.193" port: 33735 } }
I20260812 06:20:19.746469 12761 leader_election.cc:304] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad [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: 780cb545328e4547bf9973256379f5ad; no voters: 
I20260812 06:20:19.746706 12761 leader_election.cc:290] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:19.746840 12763 raft_consensus.cc:2804] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:19.747072 12761 ts_tablet_manager.cc:1434] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:20:19.747169 12763 raft_consensus.cc:697] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad [term 1 LEADER]: Becoming Leader. State: Replica: 780cb545328e4547bf9973256379f5ad, State: Running, Role: LEADER
I20260812 06:20:19.747308 12744 heartbeater.cc:499] Master 127.12.63.254:39967 was elected leader, sending a full tablet report...
I20260812 06:20:19.747376 12763 consensus_queue.cc:237] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad [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: "780cb545328e4547bf9973256379f5ad" member_type: VOTER last_known_addr { host: "127.12.63.193" port: 33735 } }
I20260812 06:20:19.750028 12580 catalog_manager.cc:5719] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad reported cstate change: term changed from 0 to 1, leader changed from <none> to 780cb545328e4547bf9973256379f5ad (127.12.63.193). New cstate: current_term: 1 leader_uuid: "780cb545328e4547bf9973256379f5ad" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "780cb545328e4547bf9973256379f5ad" member_type: VOTER last_known_addr { host: "127.12.63.193" port: 33735 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:19.824753 12543 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.065s	user 0.019s	sys 0.008s
I20260812 06:20:19.950217 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling FlushMRSOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=15.086190
I20260812 06:20:20.101783 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: FlushMRSOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.151s	user 0.118s	sys 0.032s Metrics: {"bytes_written":11897250,"cfile_init":1,"compiler_manager_pool.queue_time_us":213,"delete_count":0,"dirs.queue_time_us":75,"dirs.run_cpu_time_us":246,"dirs.run_wall_time_us":874,"drs_written":1,"lbm_read_time_us":77,"lbm_reads_lt_1ms":4,"lbm_write_time_us":37702,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":116,"threads_started":1,"update_count":1450}
I20260812 06:20:20.102836 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling MajorDeltaCompactionOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=1.000000
I20260812 06:20:20.224110 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: MajorDeltaCompactionOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.121s	user 0.095s	sys 0.019s Metrics: {"cfile_cache_miss":321,"cfile_cache_miss_bytes":16159506,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":382,"lbm_read_time_us":6796,"lbm_reads_lt_1ms":353,"lbm_write_time_us":22574,"lbm_writes_lt_1ms":333,"mutex_wait_us":315,"peak_mem_usage":36812022,"reinsert_count":0,"thread_start_us":323,"threads_started":5,"update_count":1450}
I20260812 06:20:20.224599 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling LogGCOp(3e99b2a9fc2b46a786467e82fed31e34): free 20743880 bytes of WAL
I20260812 06:20:20.224884 12672 log_reader.cc:385] T 3e99b2a9fc2b46a786467e82fed31e34: removed 2 log segments from log reader
I20260812 06:20:20.224948 12672 log.cc:1079] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/3e99b2a9fc2b46a786467e82fed31e34/wal-000000001 (ops 1-6)
I20260812 06:20:20.225013 12672 log.cc:1079] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/3e99b2a9fc2b46a786467e82fed31e34/wal-000000002 (ops 7-11)
I20260812 06:20:20.230687 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: LogGCOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.006s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:20:20.231395 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling UndoDeltaBlockGCOp(3e99b2a9fc2b46a786467e82fed31e34): 12719216 bytes on disk
I20260812 06:20:20.232023 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: UndoDeltaBlockGCOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4}
I20260812 06:20:20.232563 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=10.126437
I20260812 06:20:20.276050 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.043s	user 0.026s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17533,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:20.276564 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=2.188937
I20260812 06:20:20.287740 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4150,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.288596 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling MajorDeltaCompactionOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=1.000000
I20260812 06:20:20.416712 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: MajorDeltaCompactionOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.128s	user 0.104s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":907,"lbm_read_time_us":8892,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25365,"lbm_writes_lt_1ms":443,"mutex_wait_us":243,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":27136,"update_count":2000}
I20260812 06:20:20.417371 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=10.126437
I20260812 06:20:20.466573 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.049s	user 0.013s	sys 0.027s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":15658,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:20.467229 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=2.188937
I20260812 06:20:20.477949 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4243,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.478351 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling MajorDeltaCompactionOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=1.000000
I20260812 06:20:20.623658 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: MajorDeltaCompactionOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.145s	user 0.109s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672280,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":879,"lbm_read_time_us":10464,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22800,"lbm_writes_lt_1ms":443,"mutex_wait_us":279,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10112,"update_count":2000}
I20260812 06:20:20.624320 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=10.126437
I20260812 06:20:20.672660 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.048s	user 0.025s	sys 0.011s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16566,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:20.673110 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=2.188937
I20260812 06:20:20.684083 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4012,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.684718 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling MajorDeltaCompactionOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=1.000000
I20260812 06:20:20.814412 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: MajorDeltaCompactionOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.129s	user 0.086s	sys 0.040s 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":942,"lbm_read_time_us":8407,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23871,"lbm_writes_lt_1ms":443,"mutex_wait_us":1,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4224,"update_count":2000}
I20260812 06:20:20.815212 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=10.126437
I20260812 06:20:20.862380 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.047s	user 0.014s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14357,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:20.862886 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=2.188937
I20260812 06:20:20.874303 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4229,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.875077 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling MajorDeltaCompactionOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=1.000000
I20260812 06:20:20.993714 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: MajorDeltaCompactionOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.118s	user 0.097s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1069,"lbm_read_time_us":9786,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21864,"lbm_writes_lt_1ms":443,"mutex_wait_us":265,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3584,"update_count":2000}
I20260812 06:20:20.994379 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=10.126437
I20260812 06:20:21.047725 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.053s	user 0.030s	sys 0.015s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":19675,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":300,"reinsert_count":0,"update_count":1500}
I20260812 06:20:21.048429 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=2.188937
I20260812 06:20:21.059376 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4217,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.059988 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling MajorDeltaCompactionOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=1.000000
I20260812 06:20:21.217528 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: MajorDeltaCompactionOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.157s	user 0.085s	sys 0.064s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":816,"lbm_read_time_us":11428,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24737,"lbm_writes_lt_1ms":443,"mutex_wait_us":71,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7424,"update_count":2000}
I20260812 06:20:21.218083 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=10.126437
I20260812 06:20:21.264073 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.046s	user 0.032s	sys 0.000s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14180,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:21.264631 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=2.188937
I20260812 06:20:21.275908 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4118,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.276506 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling MajorDeltaCompactionOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=1.000000
I20260812 06:20:21.400266 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: MajorDeltaCompactionOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.124s	user 0.092s	sys 0.031s 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":389,"lbm_read_time_us":7921,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24773,"lbm_writes_lt_1ms":443,"mutex_wait_us":78,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":18816,"update_count":2000}
I20260812 06:20:21.403223 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=10.126437
I20260812 06:20:21.446491 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.043s	user 0.021s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20513,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:20:21.447065 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=2.188937
I20260812 06:20:21.457415 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3883,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.457898 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling FlushMRSOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=1.000000
I20260812 06:20:21.489070 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: FlushMRSOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.031s	user 0.025s	sys 0.004s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":62,"dirs.run_cpu_time_us":274,"dirs.run_wall_time_us":1404,"drs_written":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2737,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:21.489925 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling LogGCOp(3e99b2a9fc2b46a786467e82fed31e34): free 120553327 bytes of WAL
I20260812 06:20:21.490216 12672 log_reader.cc:385] T 3e99b2a9fc2b46a786467e82fed31e34: removed 12 log segments from log reader
I20260812 06:20:21.490275 12672 log.cc:1079] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/3e99b2a9fc2b46a786467e82fed31e34/wal-000000003 (ops 12-16)
I20260812 06:20:21.490315 12672 log.cc:1079] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/3e99b2a9fc2b46a786467e82fed31e34/wal-000000004 (ops 17-21)
I20260812 06:20:21.490348 12672 log.cc:1079] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/3e99b2a9fc2b46a786467e82fed31e34/wal-000000005 (ops 22-26)
I20260812 06:20:21.490373 12672 log.cc:1079] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/3e99b2a9fc2b46a786467e82fed31e34/wal-000000006 (ops 27-31)
I20260812 06:20:21.490401 12672 log.cc:1079] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/3e99b2a9fc2b46a786467e82fed31e34/wal-000000007 (ops 32-36)
I20260812 06:20:21.490422 12672 log.cc:1079] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/3e99b2a9fc2b46a786467e82fed31e34/wal-000000008 (ops 37-40)
I20260812 06:20:21.490453 12672 log.cc:1079] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/3e99b2a9fc2b46a786467e82fed31e34/wal-000000009 (ops 41-45)
I20260812 06:20:21.490474 12672 log.cc:1079] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/3e99b2a9fc2b46a786467e82fed31e34/wal-000000010 (ops 46-50)
I20260812 06:20:21.490504 12672 log.cc:1079] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/3e99b2a9fc2b46a786467e82fed31e34/wal-000000011 (ops 51-55)
I20260812 06:20:21.490533 12672 log.cc:1079] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/3e99b2a9fc2b46a786467e82fed31e34/wal-000000012 (ops 56-60)
I20260812 06:20:21.490566 12672 log.cc:1079] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/3e99b2a9fc2b46a786467e82fed31e34/wal-000000013 (ops 61-64)
I20260812 06:20:21.490590 12672 log.cc:1079] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/3e99b2a9fc2b46a786467e82fed31e34/wal-000000014 (ops 65-69)
I20260812 06:20:21.519302 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: LogGCOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.029s	user 0.002s	sys 0.027s Metrics: {}
I20260812 06:20:21.519763 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=2.188937
I20260812 06:20:21.540786 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.018s	user 0.003s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5343,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.541229 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling UndoDeltaBlockGCOp(3e99b2a9fc2b46a786467e82fed31e34): 473 bytes on disk
I20260812 06:20:21.541620 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: UndoDeltaBlockGCOp(3e99b2a9fc2b46a786467e82fed31e34) 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:20:21.542029 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=2.188937
I20260812 06:20:21.552570 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4088,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.553051 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling MajorDeltaCompactionOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=1.000000
I20260812 06:20:21.746878 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: MajorDeltaCompactionOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.194s	user 0.150s	sys 0.028s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877339,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":702,"lbm_read_time_us":10766,"lbm_reads_lt_1ms":674,"lbm_write_time_us":40563,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":642,"mutex_wait_us":91,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4992,"thread_start_us":81,"threads_started":1,"update_count":3000}
I20260812 06:20:21.747570 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=14.095187
I20260812 06:20:21.811537 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.064s	user 0.038s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":28284,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:20:21.811986 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=2.188937
I20260812 06:20:21.822959 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.011s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3912,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.823518 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling MajorDeltaCompactionOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=1.000000
I20260812 06:20:21.993630 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: MajorDeltaCompactionOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.170s	user 0.121s	sys 0.039s 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":382,"lbm_read_time_us":12068,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33653,"lbm_writes_lt_1ms":543,"mutex_wait_us":28,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7680,"update_count":2500}
I20260812 06:20:21.994678 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=11.118625
I20260812 06:20:22.048317 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.053s	user 0.028s	sys 0.023s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":23824,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:20:22.049085 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=2.188937
I20260812 06:20:22.072606 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.023s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6331,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.073076 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=2.188937
I20260812 06:20:22.082708 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.009s	user 0.002s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3442,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:22.083396 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling MajorDeltaCompactionOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=1.000000
I20260812 06:20:22.280208 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: MajorDeltaCompactionOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.197s	user 0.143s	sys 0.051s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"lbm_read_time_us":12356,"lbm_reads_lt_1ms":573,"lbm_write_time_us":33298,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2500}
I20260812 06:20:22.280820 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=14.095187
I20260812 06:20:22.349910 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.069s	user 0.040s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":28148,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:22.350494 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling MajorDeltaCompactionOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=1.000000
I20260812 06:20:22.490790 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: MajorDeltaCompactionOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.140s	user 0.114s	sys 0.025s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":966,"lbm_read_time_us":8872,"lbm_reads_lt_1ms":463,"lbm_write_time_us":23325,"lbm_writes_lt_1ms":443,"mutex_wait_us":264,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7936,"update_count":2000}
I20260812 06:20:22.491544 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=14.095187
I20260812 06:20:22.538646 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.047s	user 0.035s	sys 0.008s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20376,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:22.539307 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=2.188937
I20260812 06:20:22.553400 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.014s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5172,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.562919 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling MajorDeltaCompactionOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=1.000000
I20260812 06:20:22.752687 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: MajorDeltaCompactionOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.190s	user 0.150s	sys 0.037s 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":497,"lbm_read_time_us":15514,"lbm_reads_lt_1ms":564,"lbm_write_time_us":28153,"lbm_writes_lt_1ms":543,"mutex_wait_us":106,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8064,"update_count":2500}
I20260812 06:20:22.753234 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=14.095187
I20260812 06:20:22.805064 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.052s	user 0.021s	sys 0.027s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22074,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:22.805629 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=2.188937
I20260812 06:20:22.821539 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.016s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5971,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.822248 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling MajorDeltaCompactionOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=1.000000
I20260812 06:20:22.987233 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: MajorDeltaCompactionOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.165s	user 0.118s	sys 0.033s 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":1042,"lbm_read_time_us":9546,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31067,"lbm_writes_lt_1ms":543,"mutex_wait_us":376,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2500}
I20260812 06:20:22.988070 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=14.095187
I20260812 06:20:23.045303 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.057s	user 0.038s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25430,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:23.045969 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=2.188937
I20260812 06:20:23.057641 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4036,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.058171 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling FlushMRSOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=1.000000
I20260812 06:20:23.089120 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: FlushMRSOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.031s	user 0.026s	sys 0.003s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":77,"dirs.run_cpu_time_us":402,"dirs.run_wall_time_us":1546,"drs_written":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1650,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:23.089979 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling LogGCOp(3e99b2a9fc2b46a786467e82fed31e34): free 132571381 bytes of WAL
I20260812 06:20:23.090229 12672 log_reader.cc:385] T 3e99b2a9fc2b46a786467e82fed31e34: removed 13 log segments from log reader
I20260812 06:20:23.090296 12672 log.cc:1079] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/3e99b2a9fc2b46a786467e82fed31e34/wal-000000015 (ops 70-74)
I20260812 06:20:23.090364 12672 log.cc:1079] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/3e99b2a9fc2b46a786467e82fed31e34/wal-000000016 (ops 75-79)
I20260812 06:20:23.090425 12672 log.cc:1079] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/3e99b2a9fc2b46a786467e82fed31e34/wal-000000017 (ops 80-84)
I20260812 06:20:23.090468 12672 log.cc:1079] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/3e99b2a9fc2b46a786467e82fed31e34/wal-000000018 (ops 85-89)
I20260812 06:20:23.090507 12672 log.cc:1079] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/3e99b2a9fc2b46a786467e82fed31e34/wal-000000019 (ops 90-94)
I20260812 06:20:23.090546 12672 log.cc:1079] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/3e99b2a9fc2b46a786467e82fed31e34/wal-000000020 (ops 95-98)
I20260812 06:20:23.090587 12672 log.cc:1079] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/3e99b2a9fc2b46a786467e82fed31e34/wal-000000021 (ops 99-103)
I20260812 06:20:23.090626 12672 log.cc:1079] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/3e99b2a9fc2b46a786467e82fed31e34/wal-000000022 (ops 104-108)
I20260812 06:20:23.090667 12672 log.cc:1079] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/3e99b2a9fc2b46a786467e82fed31e34/wal-000000023 (ops 109-113)
I20260812 06:20:23.090706 12672 log.cc:1079] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/3e99b2a9fc2b46a786467e82fed31e34/wal-000000024 (ops 114-118)
I20260812 06:20:23.090746 12672 log.cc:1079] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/3e99b2a9fc2b46a786467e82fed31e34/wal-000000025 (ops 119-123)
I20260812 06:20:23.090785 12672 log.cc:1079] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/3e99b2a9fc2b46a786467e82fed31e34/wal-000000026 (ops 124-128)
I20260812 06:20:23.090821 12672 log.cc:1079] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/3e99b2a9fc2b46a786467e82fed31e34/wal-000000027 (ops 129-132)
I20260812 06:20:23.121728 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: LogGCOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.032s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:20:23.122483 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling UndoDeltaBlockGCOp(3e99b2a9fc2b46a786467e82fed31e34): 482 bytes on disk
I20260812 06:20:23.123459 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: UndoDeltaBlockGCOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4}
I20260812 06:20:23.124045 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=4.173312
I20260812 06:20:23.151816 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.028s	user 0.015s	sys 0.012s Metrics: {"bytes_written":5661585,"delete_count":0,"lbm_write_time_us":6997,"lbm_writes_lt_1ms":141,"reinsert_count":0,"update_count":690}
I20260812 06:20:23.152576 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=1.196750
I20260812 06:20:23.164723 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":2543704,"delete_count":0,"lbm_write_time_us":3963,"lbm_writes_lt_1ms":65,"reinsert_count":0,"update_count":310}
I20260812 06:20:23.165319 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling MajorDeltaCompactionOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=1.000000
I20260812 06:20:23.394598 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: MajorDeltaCompactionOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.229s	user 0.153s	sys 0.076s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979715,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1547,"lbm_read_time_us":16924,"lbm_reads_lt_1ms":774,"lbm_write_time_us":38460,"lbm_writes_lt_1ms":743,"mutex_wait_us":534,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":7424,"thread_start_us":82,"threads_started":1,"update_count":3500}
I20260812 06:20:23.395288 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=14.095187
I20260812 06:20:23.455494 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.060s	user 0.021s	sys 0.022s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20003,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:23.456107 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=2.188937
I20260812 06:20:23.469281 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.013s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4718,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.469976 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling MajorDeltaCompactionOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=1.000000
I20260812 06:20:23.637831 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: MajorDeltaCompactionOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.168s	user 0.133s	sys 0.032s 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":550,"lbm_read_time_us":11615,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29493,"lbm_writes_lt_1ms":543,"mutex_wait_us":53,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10496,"update_count":2500}
I20260812 06:20:23.638442 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=11.118625
I20260812 06:20:23.673925 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.035s	user 0.017s	sys 0.016s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":14753,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:23.674749 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=2.188937
I20260812 06:20:23.693949 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.019s	user 0.010s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5968,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:23.694422 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling MajorDeltaCompactionOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=1.000000
I20260812 06:20:23.842983 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: MajorDeltaCompactionOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.148s	user 0.111s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672270,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":359,"lbm_read_time_us":9267,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25412,"lbm_writes_lt_1ms":443,"mutex_wait_us":24,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6912,"update_count":2000}
I20260812 06:20:23.845701 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=11.118625
I20260812 06:20:23.887338 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.041s	user 0.027s	sys 0.014s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":18274,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:23.887923 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=2.188937
I20260812 06:20:23.899389 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.011s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3990,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:23.899847 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling MajorDeltaCompactionOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=1.000000
I20260812 06:20:24.037109 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: MajorDeltaCompactionOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.137s	user 0.093s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":896,"lbm_read_time_us":9060,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25592,"lbm_writes_lt_1ms":443,"mutex_wait_us":328,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16768,"update_count":2000}
I20260812 06:20:24.037792 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=10.126437
I20260812 06:20:24.081033 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.043s	user 0.016s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17671,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:24.081622 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=2.188937
I20260812 06:20:24.097165 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6129,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.097668 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling MajorDeltaCompactionOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=1.000000
I20260812 06:20:24.234499 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: MajorDeltaCompactionOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.137s	user 0.091s	sys 0.044s 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":621,"lbm_read_time_us":10456,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27407,"lbm_writes_lt_1ms":443,"mutex_wait_us":298,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":22528,"update_count":2000}
I20260812 06:20:24.235280 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=11.118625
I20260812 06:20:24.277464 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.042s	user 0.012s	sys 0.028s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14353,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:24.278244 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=2.188937
I20260812 06:20:24.289510 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4121,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:24.290050 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling MajorDeltaCompactionOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=1.000000
I20260812 06:20:24.452462 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: MajorDeltaCompactionOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.162s	user 0.116s	sys 0.046s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":296,"lbm_read_time_us":11491,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26935,"lbm_writes_lt_1ms":443,"mutex_wait_us":45,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":18816,"update_count":2000}
I20260812 06:20:24.453102 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=10.126437
I20260812 06:20:24.498220 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.045s	user 0.016s	sys 0.021s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":18936,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:20:24.498766 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=2.188937
I20260812 06:20:24.509979 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4012,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.510612 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling MajorDeltaCompactionOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=1.000000
I20260812 06:20:24.635921 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: MajorDeltaCompactionOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.125s	user 0.095s	sys 0.030s 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":1056,"lbm_read_time_us":9327,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23198,"lbm_writes_lt_1ms":443,"mutex_wait_us":21,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2000}
I20260812 06:20:24.636665 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=10.126437
I20260812 06:20:24.679970 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.043s	user 0.017s	sys 0.017s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":15319,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:24.680586 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=2.188937
I20260812 06:20:24.694378 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.014s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4631,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.695175 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling FlushMRSOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=1.000000
I20260812 06:20:24.725965 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: FlushMRSOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.031s	user 0.024s	sys 0.004s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":99,"dirs.run_cpu_time_us":236,"dirs.run_wall_time_us":1298,"drs_written":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2415,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:24.726754 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling LogGCOp(3e99b2a9fc2b46a786467e82fed31e34): free 121006647 bytes of WAL
I20260812 06:20:24.727052 12672 log_reader.cc:385] T 3e99b2a9fc2b46a786467e82fed31e34: removed 12 log segments from log reader
I20260812 06:20:24.727111 12672 log.cc:1079] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/3e99b2a9fc2b46a786467e82fed31e34/wal-000000028 (ops 133-137)
I20260812 06:20:24.727159 12672 log.cc:1079] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/3e99b2a9fc2b46a786467e82fed31e34/wal-000000029 (ops 138-142)
I20260812 06:20:24.727190 12672 log.cc:1079] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/3e99b2a9fc2b46a786467e82fed31e34/wal-000000030 (ops 143-147)
I20260812 06:20:24.727219 12672 log.cc:1079] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/3e99b2a9fc2b46a786467e82fed31e34/wal-000000031 (ops 148-152)
I20260812 06:20:24.727253 12672 log.cc:1079] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/3e99b2a9fc2b46a786467e82fed31e34/wal-000000032 (ops 153-157)
I20260812 06:20:24.727286 12672 log.cc:1079] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/3e99b2a9fc2b46a786467e82fed31e34/wal-000000033 (ops 158-162)
I20260812 06:20:24.727315 12672 log.cc:1079] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/3e99b2a9fc2b46a786467e82fed31e34/wal-000000034 (ops 163-166)
I20260812 06:20:24.727337 12672 log.cc:1079] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/3e99b2a9fc2b46a786467e82fed31e34/wal-000000035 (ops 167-171)
I20260812 06:20:24.727360 12672 log.cc:1079] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/3e99b2a9fc2b46a786467e82fed31e34/wal-000000036 (ops 172-176)
I20260812 06:20:24.727391 12672 log.cc:1079] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/3e99b2a9fc2b46a786467e82fed31e34/wal-000000037 (ops 177-181)
I20260812 06:20:24.727423 12672 log.cc:1079] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/3e99b2a9fc2b46a786467e82fed31e34/wal-000000038 (ops 182-186)
I20260812 06:20:24.727455 12672 log.cc:1079] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/3e99b2a9fc2b46a786467e82fed31e34/wal-000000039 (ops 187-191)
I20260812 06:20:24.755008 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: LogGCOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.028s	user 0.001s	sys 0.023s Metrics: {}
I20260812 06:20:24.755510 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling UndoDeltaBlockGCOp(3e99b2a9fc2b46a786467e82fed31e34): 483 bytes on disk
I20260812 06:20:24.756234 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: UndoDeltaBlockGCOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4}
I20260812 06:20:24.756958 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=3.181125
I20260812 06:20:24.778035 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.021s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":7269,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:24.778492 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=2.188937
I20260812 06:20:24.789862 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4049,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:24.790376 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling MajorDeltaCompactionOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=1.000000
I20260812 06:20:24.865410 12543 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.041s	user 1.851s	sys 0.178s
I20260812 06:20:24.950695 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: MajorDeltaCompactionOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.160s	user 0.103s	sys 0.057s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877329,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":986,"lbm_read_time_us":12156,"lbm_reads_lt_1ms":670,"lbm_write_time_us":31429,"lbm_writes_lt_1ms":643,"mutex_wait_us":80,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":18432,"thread_start_us":148,"threads_started":1,"update_count":3000}
I20260812 06:20:24.953992 12745 maintenance_manager.cc:419] P 780cb545328e4547bf9973256379f5ad: Scheduling FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34): perf score=6.157687
I20260812 06:20:24.959822 12543 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.094s	user 0.004s	sys 0.000s
I20260812 06:20:24.960606 12543 tablet_server.cc:179] TabletServer@127.12.63.193:0 shutting down...
I20260812 06:20:24.981114 12672 maintenance_manager.cc:643] P 780cb545328e4547bf9973256379f5ad: FlushDeltaMemStoresOp(3e99b2a9fc2b46a786467e82fed31e34) complete. Timing: real 0.027s	user 0.021s	sys 0.003s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":11666,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:20:24.981771 12543 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:24.982218 12543 tablet_replica.cc:333] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad: stopping tablet replica
I20260812 06:20:24.982529 12543 raft_consensus.cc:2243] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:24.982776 12543 raft_consensus.cc:2272] T 3e99b2a9fc2b46a786467e82fed31e34 P 780cb545328e4547bf9973256379f5ad [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:25.000473 12543 tablet_server.cc:196] TabletServer@127.12.63.193:0 shutdown complete.
I20260812 06:20:25.005820 12543 master.cc:562] Master@127.12.63.254:39967 shutting down...
I20260812 06:20:25.011420 12543 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 47495066a2644665a198c62b4f5f98e4 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:25.011791 12543 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 47495066a2644665a198c62b4f5f98e4 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:25.011917 12543 tablet_replica.cc:333] T 00000000000000000000000000000000 P 47495066a2644665a198c62b4f5f98e4: stopping tablet replica
I20260812 06:20:25.025285 12543 master.cc:584] Master@127.12.63.254:39967 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5556 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:20:25.113157 12543 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.12.63.254:46137
I20260812 06:20:25.113584 12543 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:25.116508 12787 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:25.116647 12785 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:25.116508 12783 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:25.116662 12543 server_base.cc:1061] running on GCE node
I20260812 06:20:25.117131 12543 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:25.117182 12543 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:25.117201 12543 hybrid_clock.cc:648] HybridClock initialized: now 1786515625117201 us; error 0 us; skew 500 ppm
I20260812 06:20:25.118419 12543 webserver.cc:533] Webserver started at http://127.12.63.254:37029/ using document root <none> and password file <none>
I20260812 06:20:25.118690 12543 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:25.118759 12543 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:25.118896 12543 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:25.119508 12543 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619545971-12543-0/minicluster-data/master-0-root/instance:
uuid: "9b1dd650c84f4e009264d5c4816e9678"
format_stamp: "Formatted at 2026-08-12 06:20:25 on dist-test-slave-wl2h"
I20260812 06:20:25.121837 12543 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:20:25.123597 12792 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:25.124145 12543 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.001s
I20260812 06:20:25.124280 12543 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619545971-12543-0/minicluster-data/master-0-root
uuid: "9b1dd650c84f4e009264d5c4816e9678"
format_stamp: "Formatted at 2026-08-12 06:20:25 on dist-test-slave-wl2h"
I20260812 06:20:25.124379 12543 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619545971-12543-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619545971-12543-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619545971-12543-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:25.143797 12543 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:25.144209 12543 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:25.149027 12543 rpc_server.cc:307] RPC server started. Bound to: 127.12.63.254:46137
I20260812 06:20:25.149638 12858 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.12.63.254:46137 every 8 connection(s)
I20260812 06:20:25.150861 12859 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:25.169257 12859 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 9b1dd650c84f4e009264d5c4816e9678: Bootstrap starting.
I20260812 06:20:25.170295 12859 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 9b1dd650c84f4e009264d5c4816e9678: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:25.171556 12859 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 9b1dd650c84f4e009264d5c4816e9678: No bootstrap required, opened a new log
I20260812 06:20:25.172015 12859 raft_consensus.cc:359] T 00000000000000000000000000000000 P 9b1dd650c84f4e009264d5c4816e9678 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9b1dd650c84f4e009264d5c4816e9678" member_type: VOTER }
I20260812 06:20:25.172204 12859 raft_consensus.cc:385] T 00000000000000000000000000000000 P 9b1dd650c84f4e009264d5c4816e9678 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:25.172271 12859 raft_consensus.cc:740] T 00000000000000000000000000000000 P 9b1dd650c84f4e009264d5c4816e9678 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 9b1dd650c84f4e009264d5c4816e9678, State: Initialized, Role: FOLLOWER
I20260812 06:20:25.172448 12859 consensus_queue.cc:260] T 00000000000000000000000000000000 P 9b1dd650c84f4e009264d5c4816e9678 [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: "9b1dd650c84f4e009264d5c4816e9678" member_type: VOTER }
I20260812 06:20:25.172578 12859 raft_consensus.cc:399] T 00000000000000000000000000000000 P 9b1dd650c84f4e009264d5c4816e9678 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:25.172631 12859 raft_consensus.cc:493] T 00000000000000000000000000000000 P 9b1dd650c84f4e009264d5c4816e9678 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:25.172695 12859 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 9b1dd650c84f4e009264d5c4816e9678 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:25.173583 12859 raft_consensus.cc:515] T 00000000000000000000000000000000 P 9b1dd650c84f4e009264d5c4816e9678 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9b1dd650c84f4e009264d5c4816e9678" member_type: VOTER }
I20260812 06:20:25.173765 12859 leader_election.cc:304] T 00000000000000000000000000000000 P 9b1dd650c84f4e009264d5c4816e9678 [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: 9b1dd650c84f4e009264d5c4816e9678; no voters: 
I20260812 06:20:25.174045 12859 leader_election.cc:290] T 00000000000000000000000000000000 P 9b1dd650c84f4e009264d5c4816e9678 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:25.174273 12862 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 9b1dd650c84f4e009264d5c4816e9678 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:25.174497 12862 raft_consensus.cc:697] T 00000000000000000000000000000000 P 9b1dd650c84f4e009264d5c4816e9678 [term 1 LEADER]: Becoming Leader. State: Replica: 9b1dd650c84f4e009264d5c4816e9678, State: Running, Role: LEADER
I20260812 06:20:25.174604 12859 sys_catalog.cc:565] T 00000000000000000000000000000000 P 9b1dd650c84f4e009264d5c4816e9678 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:25.174715 12862 consensus_queue.cc:237] T 00000000000000000000000000000000 P 9b1dd650c84f4e009264d5c4816e9678 [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: "9b1dd650c84f4e009264d5c4816e9678" member_type: VOTER }
I20260812 06:20:25.175374 12864 sys_catalog.cc:455] T 00000000000000000000000000000000 P 9b1dd650c84f4e009264d5c4816e9678 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 9b1dd650c84f4e009264d5c4816e9678. Latest consensus state: current_term: 1 leader_uuid: "9b1dd650c84f4e009264d5c4816e9678" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9b1dd650c84f4e009264d5c4816e9678" member_type: VOTER } }
I20260812 06:20:25.175480 12864 sys_catalog.cc:458] T 00000000000000000000000000000000 P 9b1dd650c84f4e009264d5c4816e9678 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:25.175616 12863 sys_catalog.cc:455] T 00000000000000000000000000000000 P 9b1dd650c84f4e009264d5c4816e9678 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "9b1dd650c84f4e009264d5c4816e9678" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9b1dd650c84f4e009264d5c4816e9678" member_type: VOTER } }
I20260812 06:20:25.175684 12863 sys_catalog.cc:458] T 00000000000000000000000000000000 P 9b1dd650c84f4e009264d5c4816e9678 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:25.176184 12870 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:25.176918 12870 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:25.177320 12543 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:25.179076 12870 catalog_manager.cc:1383] Generated new cluster ID: 43f38159fee446119422c65820b296e3
I20260812 06:20:25.179143 12870 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:25.196961 12870 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:25.197566 12870 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:25.206950 12870 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 9b1dd650c84f4e009264d5c4816e9678: Generated new TSK 0
I20260812 06:20:25.207172 12870 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:25.210156 12543 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:20:25.212644 12543 server_base.cc:1061] running on GCE node
W20260812 06:20:25.212644 12886 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:25.212730 12883 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:25.212684 12882 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:25.213197 12543 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:25.213255 12543 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:25.213272 12543 hybrid_clock.cc:648] HybridClock initialized: now 1786515625213273 us; error 0 us; skew 500 ppm
I20260812 06:20:25.214360 12543 webserver.cc:533] Webserver started at http://127.12.63.193:44117/ using document root <none> and password file <none>
I20260812 06:20:25.214576 12543 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:25.214630 12543 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:25.214751 12543 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:25.215292 12543 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619545971-12543-0/minicluster-data/ts-0-root/instance:
uuid: "5422cc919a2f4993bc66732504c63ac9"
format_stamp: "Formatted at 2026-08-12 06:20:25 on dist-test-slave-wl2h"
I20260812 06:20:25.217021 12543 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:25.218266 12891 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:25.218583 12543 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:25.218657 12543 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619545971-12543-0/minicluster-data/ts-0-root
uuid: "5422cc919a2f4993bc66732504c63ac9"
format_stamp: "Formatted at 2026-08-12 06:20:25 on dist-test-slave-wl2h"
I20260812 06:20:25.218761 12543 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619545971-12543-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619545971-12543-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619545971-12543-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:25.234508 12543 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:25.235005 12543 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:25.235483 12543 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:25.236138 12543 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:25.236186 12543 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:25.236258 12543 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:25.236299 12543 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:25.241170 12543 rpc_server.cc:307] RPC server started. Bound to: 127.12.63.193:45187
I20260812 06:20:25.241268 12971 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.12.63.193:45187 every 8 connection(s)
I20260812 06:20:25.251971 12972 heartbeater.cc:344] Connected to a master server at 127.12.63.254:46137
I20260812 06:20:25.252117 12972 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:25.252362 12972 heartbeater.cc:507] Master 127.12.63.254:46137 requested a full tablet report, sending...
I20260812 06:20:25.253142 12811 ts_manager.cc:194] Registered new tserver with Master: 5422cc919a2f4993bc66732504c63ac9 (127.12.63.193:45187)
I20260812 06:20:25.253196 12543 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011561351s
I20260812 06:20:25.254022 12811 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:37340
I20260812 06:20:25.261270 12811 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:37354:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:20:25.270401 12926 tablet_service.cc:1511] Processing CreateTablet for tablet 6b5600afaa354efcaf3933b33f537c83 (DEFAULT_TABLE table=heavy-update-compaction-test [id=e9d45c29ce1c44cab191828e324e9c9d]), partition=
I20260812 06:20:25.270741 12926 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 6b5600afaa354efcaf3933b33f537c83. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:25.272755 12987 tablet_bootstrap.cc:492] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9: Bootstrap starting.
I20260812 06:20:25.273758 12987 tablet_bootstrap.cc:654] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:25.274876 12987 tablet_bootstrap.cc:492] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9: No bootstrap required, opened a new log
I20260812 06:20:25.274955 12987 ts_tablet_manager.cc:1403] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:25.275477 12987 raft_consensus.cc:359] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5422cc919a2f4993bc66732504c63ac9" member_type: VOTER last_known_addr { host: "127.12.63.193" port: 45187 } }
I20260812 06:20:25.275570 12987 raft_consensus.cc:385] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:25.275592 12987 raft_consensus.cc:740] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 5422cc919a2f4993bc66732504c63ac9, State: Initialized, Role: FOLLOWER
I20260812 06:20:25.275738 12987 consensus_queue.cc:260] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9 [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: "5422cc919a2f4993bc66732504c63ac9" member_type: VOTER last_known_addr { host: "127.12.63.193" port: 45187 } }
I20260812 06:20:25.275820 12987 raft_consensus.cc:399] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:25.275844 12987 raft_consensus.cc:493] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:25.275906 12987 raft_consensus.cc:3060] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:25.276789 12987 raft_consensus.cc:515] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5422cc919a2f4993bc66732504c63ac9" member_type: VOTER last_known_addr { host: "127.12.63.193" port: 45187 } }
I20260812 06:20:25.276924 12987 leader_election.cc:304] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9 [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: 5422cc919a2f4993bc66732504c63ac9; no voters: 
I20260812 06:20:25.277097 12987 leader_election.cc:290] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:25.277233 12989 raft_consensus.cc:2804] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:25.277468 12987 ts_tablet_manager.cc:1434] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:20:25.277536 12989 raft_consensus.cc:697] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9 [term 1 LEADER]: Becoming Leader. State: Replica: 5422cc919a2f4993bc66732504c63ac9, State: Running, Role: LEADER
I20260812 06:20:25.277559 12972 heartbeater.cc:499] Master 127.12.63.254:46137 was elected leader, sending a full tablet report...
I20260812 06:20:25.277761 12989 consensus_queue.cc:237] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9 [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: "5422cc919a2f4993bc66732504c63ac9" member_type: VOTER last_known_addr { host: "127.12.63.193" port: 45187 } }
I20260812 06:20:25.279269 12811 catalog_manager.cc:5719] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9 reported cstate change: term changed from 0 to 1, leader changed from <none> to 5422cc919a2f4993bc66732504c63ac9 (127.12.63.193). New cstate: current_term: 1 leader_uuid: "5422cc919a2f4993bc66732504c63ac9" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5422cc919a2f4993bc66732504c63ac9" member_type: VOTER last_known_addr { host: "127.12.63.193" port: 45187 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:25.343986 12543 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.056s	user 0.013s	sys 0.011s
I20260812 06:20:25.492164 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling FlushMRSOp(6b5600afaa354efcaf3933b33f537c83): perf score=19.054940
I20260812 06:20:25.649101 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: FlushMRSOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.157s	user 0.113s	sys 0.039s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":56,"dirs.run_cpu_time_us":215,"dirs.run_wall_time_us":790,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40525,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:20:25.649744 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling LogGCOp(6b5600afaa354efcaf3933b33f537c83): free 20290830 bytes of WAL
I20260812 06:20:25.649993 12896 log_reader.cc:385] T 6b5600afaa354efcaf3933b33f537c83: removed 2 log segments from log reader
I20260812 06:20:25.650036 12896 log.cc:1079] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/6b5600afaa354efcaf3933b33f537c83/wal-000000001 (ops 1-6)
I20260812 06:20:25.650066 12896 log.cc:1079] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/6b5600afaa354efcaf3933b33f537c83/wal-000000002 (ops 7-10)
I20260812 06:20:25.654199 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: LogGCOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.004s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:20:25.654613 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling UndoDeltaBlockGCOp(6b5600afaa354efcaf3933b33f537c83): 16411393 bytes on disk
I20260812 06:20:25.655095 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: UndoDeltaBlockGCOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4}
I20260812 06:20:25.655499 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83): perf score=2.188937
I20260812 06:20:25.672622 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.017s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4730,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.673064 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling MajorDeltaCompactionOp(6b5600afaa354efcaf3933b33f537c83): perf score=1.000000
I20260812 06:20:25.822114 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: MajorDeltaCompactionOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.149s	user 0.099s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":609,"lbm_read_time_us":10024,"lbm_reads_lt_1ms":460,"lbm_write_time_us":25122,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":316,"threads_started":5,"update_count":2000}
I20260812 06:20:25.822677 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83): perf score=14.095187
I20260812 06:20:25.871376 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.049s	user 0.020s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20394,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:25.871835 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83): perf score=2.188937
I20260812 06:20:25.883457 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.011s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3965,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.884177 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling MajorDeltaCompactionOp(6b5600afaa354efcaf3933b33f537c83): perf score=1.000000
I20260812 06:20:26.048832 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: MajorDeltaCompactionOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.164s	user 0.116s	sys 0.047s 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":1271,"lbm_read_time_us":11590,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31964,"lbm_writes_lt_1ms":543,"mutex_wait_us":349,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14848,"update_count":2500}
I20260812 06:20:26.049571 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83): perf score=11.118625
I20260812 06:20:26.095777 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.046s	user 0.034s	sys 0.011s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":19108,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:20:26.096350 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83): perf score=2.188937
I20260812 06:20:26.111577 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5354,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:26.112020 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling MajorDeltaCompactionOp(6b5600afaa354efcaf3933b33f537c83): perf score=1.000000
I20260812 06:20:26.281431 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: MajorDeltaCompactionOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.169s	user 0.122s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672267,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1434,"lbm_read_time_us":10239,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26461,"lbm_writes_lt_1ms":443,"mutex_wait_us":86,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10368,"update_count":2000}
I20260812 06:20:26.282042 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83): perf score=14.095187
I20260812 06:20:26.331724 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.049s	user 0.025s	sys 0.015s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":18529,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:26.332263 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83): perf score=2.188937
I20260812 06:20:26.353130 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.021s	user 0.009s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4286,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.353678 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling MajorDeltaCompactionOp(6b5600afaa354efcaf3933b33f537c83): perf score=1.000000
I20260812 06:20:26.546555 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: MajorDeltaCompactionOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.193s	user 0.101s	sys 0.085s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":567,"lbm_read_time_us":13238,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29482,"lbm_writes_lt_1ms":543,"mutex_wait_us":53,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:20:26.547264 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83): perf score=14.095187
I20260812 06:20:26.601065 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.054s	user 0.039s	sys 0.008s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21717,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:26.601527 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83): perf score=2.188937
I20260812 06:20:26.613291 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.012s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4263,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.613947 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling MajorDeltaCompactionOp(6b5600afaa354efcaf3933b33f537c83): perf score=1.000000
I20260812 06:20:26.802845 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: MajorDeltaCompactionOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.189s	user 0.112s	sys 0.065s 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":585,"lbm_read_time_us":11539,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27680,"lbm_writes_lt_1ms":543,"mutex_wait_us":277,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":20736,"update_count":2500}
I20260812 06:20:26.803454 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83): perf score=14.095187
I20260812 06:20:26.852716 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.049s	user 0.017s	sys 0.024s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":18681,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:26.853286 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83): perf score=2.188937
I20260812 06:20:26.866920 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.013s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5538,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.867472 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling FlushMRSOp(6b5600afaa354efcaf3933b33f537c83): perf score=1.000000
I20260812 06:20:26.898244 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: FlushMRSOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.031s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":85,"dirs.run_cpu_time_us":208,"dirs.run_wall_time_us":1573,"drs_written":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1578,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:26.898890 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling LogGCOp(6b5600afaa354efcaf3933b33f537c83): free 108988499 bytes of WAL
I20260812 06:20:26.899209 12896 log_reader.cc:385] T 6b5600afaa354efcaf3933b33f537c83: removed 11 log segments from log reader
I20260812 06:20:26.899287 12896 log.cc:1079] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/6b5600afaa354efcaf3933b33f537c83/wal-000000003 (ops 11-15)
I20260812 06:20:26.899345 12896 log.cc:1079] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/6b5600afaa354efcaf3933b33f537c83/wal-000000004 (ops 16-20)
I20260812 06:20:26.899406 12896 log.cc:1079] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/6b5600afaa354efcaf3933b33f537c83/wal-000000005 (ops 21-25)
I20260812 06:20:26.899451 12896 log.cc:1079] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/6b5600afaa354efcaf3933b33f537c83/wal-000000006 (ops 26-30)
I20260812 06:20:26.899494 12896 log.cc:1079] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/6b5600afaa354efcaf3933b33f537c83/wal-000000007 (ops 31-35)
I20260812 06:20:26.899536 12896 log.cc:1079] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/6b5600afaa354efcaf3933b33f537c83/wal-000000008 (ops 36-40)
I20260812 06:20:26.899577 12896 log.cc:1079] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/6b5600afaa354efcaf3933b33f537c83/wal-000000009 (ops 41-44)
I20260812 06:20:26.899618 12896 log.cc:1079] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/6b5600afaa354efcaf3933b33f537c83/wal-000000010 (ops 45-49)
I20260812 06:20:26.899657 12896 log.cc:1079] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/6b5600afaa354efcaf3933b33f537c83/wal-000000011 (ops 50-54)
I20260812 06:20:26.899698 12896 log.cc:1079] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/6b5600afaa354efcaf3933b33f537c83/wal-000000012 (ops 55-59)
I20260812 06:20:26.899739 12896 log.cc:1079] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/6b5600afaa354efcaf3933b33f537c83/wal-000000013 (ops 60-64)
I20260812 06:20:26.925958 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: LogGCOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.027s	user 0.002s	sys 0.025s Metrics: {}
I20260812 06:20:26.926535 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling UndoDeltaBlockGCOp(6b5600afaa354efcaf3933b33f537c83): 448 bytes on disk
I20260812 06:20:26.927201 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: UndoDeltaBlockGCOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":67,"lbm_reads_lt_1ms":4}
I20260812 06:20:26.927747 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83): perf score=3.181125
I20260812 06:20:26.941920 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.014s	user 0.008s	sys 0.003s Metrics: {"bytes_written":4389828,"delete_count":0,"lbm_write_time_us":4585,"lbm_writes_lt_1ms":110,"reinsert_count":0,"update_count":535}
I20260812 06:20:26.942467 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83): perf score=2.188937
I20260812 06:20:26.956266 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.014s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3815483,"delete_count":0,"lbm_write_time_us":5383,"lbm_writes_lt_1ms":96,"reinsert_count":0,"update_count":465}
I20260812 06:20:26.956686 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling MajorDeltaCompactionOp(6b5600afaa354efcaf3933b33f537c83): perf score=1.000000
I20260812 06:20:27.201640 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: MajorDeltaCompactionOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.245s	user 0.177s	sys 0.067s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979745,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":146,"lbm_read_time_us":18568,"lbm_reads_lt_1ms":774,"lbm_write_time_us":37081,"lbm_writes_lt_1ms":743,"mutex_wait_us":32,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":88960,"thread_start_us":87,"threads_started":1,"update_count":3500}
I20260812 06:20:27.202286 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83): perf score=15.087375
I20260812 06:20:27.263484 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.061s	user 0.041s	sys 0.020s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":26411,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:20:27.264174 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83): perf score=2.188937
I20260812 06:20:27.278831 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.014s	user 0.008s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5329,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:27.279347 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling MajorDeltaCompactionOp(6b5600afaa354efcaf3933b33f537c83): perf score=1.000000
I20260812 06:20:27.454394 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: MajorDeltaCompactionOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.175s	user 0.122s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774675,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":167,"lbm_read_time_us":13083,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30596,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7936,"update_count":2500}
I20260812 06:20:27.455119 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83): perf score=14.095187
I20260812 06:20:27.513298 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.058s	user 0.032s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21152,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:27.514029 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83): perf score=2.188937
I20260812 06:20:27.525236 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4240,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.525782 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling MajorDeltaCompactionOp(6b5600afaa354efcaf3933b33f537c83): perf score=1.000000
I20260812 06:20:27.702770 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: MajorDeltaCompactionOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.177s	user 0.124s	sys 0.050s 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":2283,"lbm_read_time_us":12516,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28534,"lbm_writes_lt_1ms":543,"mutex_wait_us":1083,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:27.703394 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83): perf score=11.118625
I20260812 06:20:27.739892 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.036s	user 0.023s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15688,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:27.740465 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83): perf score=2.188937
I20260812 06:20:27.771236 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.031s	user 0.011s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5352,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:27.771875 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83): perf score=2.188937
I20260812 06:20:27.784421 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.012s	user 0.002s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5048,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.785028 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling MajorDeltaCompactionOp(6b5600afaa354efcaf3933b33f537c83): perf score=1.000000
I20260812 06:20:27.962528 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: MajorDeltaCompactionOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.177s	user 0.105s	sys 0.068s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":249,"lbm_read_time_us":12534,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29003,"lbm_writes_lt_1ms":543,"mutex_wait_us":3,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:27.963285 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83): perf score=14.095187
I20260812 06:20:28.017897 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.054s	user 0.026s	sys 0.016s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":19809,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:28.018529 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83): perf score=2.188937
I20260812 06:20:28.044606 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.026s	user 0.010s	sys 0.014s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5928,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.045195 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling MajorDeltaCompactionOp(6b5600afaa354efcaf3933b33f537c83): perf score=1.000000
I20260812 06:20:28.221758 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: MajorDeltaCompactionOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.176s	user 0.100s	sys 0.076s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":315,"lbm_read_time_us":11873,"lbm_reads_lt_1ms":564,"lbm_write_time_us":27258,"lbm_writes_lt_1ms":543,"mutex_wait_us":32,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":17792,"update_count":2500}
I20260812 06:20:28.222337 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83): perf score=14.095187
I20260812 06:20:28.274094 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.052s	user 0.036s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23109,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:28.274649 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83): perf score=2.188937
I20260812 06:20:28.286589 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4102,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.287221 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling MajorDeltaCompactionOp(6b5600afaa354efcaf3933b33f537c83): perf score=1.000000
I20260812 06:20:28.456353 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: MajorDeltaCompactionOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.169s	user 0.110s	sys 0.055s 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":292,"lbm_read_time_us":10367,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26777,"lbm_writes_lt_1ms":543,"mutex_wait_us":88,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:20:28.457015 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83): perf score=14.095187
I20260812 06:20:28.509230 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.052s	user 0.023s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22300,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:28.509874 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83): perf score=2.188937
I20260812 06:20:28.521703 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4141,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.522220 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling FlushMRSOp(6b5600afaa354efcaf3933b33f537c83): perf score=1.000000
I20260812 06:20:28.550933 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: FlushMRSOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.029s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":69,"dirs.run_cpu_time_us":229,"dirs.run_wall_time_us":1503,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2136,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:20:28.551636 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling LogGCOp(6b5600afaa354efcaf3933b33f537c83): free 136275182 bytes of WAL
I20260812 06:20:28.551862 12896 log_reader.cc:385] T 6b5600afaa354efcaf3933b33f537c83: removed 13 log segments from log reader
I20260812 06:20:28.551923 12896 log.cc:1079] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/6b5600afaa354efcaf3933b33f537c83/wal-000000014 (ops 65-69)
I20260812 06:20:28.551975 12896 log.cc:1079] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/6b5600afaa354efcaf3933b33f537c83/wal-000000015 (ops 70-74)
I20260812 06:20:28.552035 12896 log.cc:1079] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/6b5600afaa354efcaf3933b33f537c83/wal-000000016 (ops 75-79)
I20260812 06:20:28.552096 12896 log.cc:1079] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/6b5600afaa354efcaf3933b33f537c83/wal-000000017 (ops 80-84)
I20260812 06:20:28.552135 12896 log.cc:1079] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/6b5600afaa354efcaf3933b33f537c83/wal-000000018 (ops 85-89)
I20260812 06:20:28.552179 12896 log.cc:1079] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/6b5600afaa354efcaf3933b33f537c83/wal-000000019 (ops 90-94)
I20260812 06:20:28.552217 12896 log.cc:1079] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/6b5600afaa354efcaf3933b33f537c83/wal-000000020 (ops 95-99)
I20260812 06:20:28.552254 12896 log.cc:1079] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/6b5600afaa354efcaf3933b33f537c83/wal-000000021 (ops 100-104)
I20260812 06:20:28.552291 12896 log.cc:1079] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/6b5600afaa354efcaf3933b33f537c83/wal-000000022 (ops 105-109)
I20260812 06:20:28.552328 12896 log.cc:1079] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/6b5600afaa354efcaf3933b33f537c83/wal-000000023 (ops 110-114)
I20260812 06:20:28.552366 12896 log.cc:1079] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/6b5600afaa354efcaf3933b33f537c83/wal-000000024 (ops 115-118)
I20260812 06:20:28.552402 12896 log.cc:1079] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/6b5600afaa354efcaf3933b33f537c83/wal-000000025 (ops 119-123)
I20260812 06:20:28.552438 12896 log.cc:1079] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/6b5600afaa354efcaf3933b33f537c83/wal-000000026 (ops 124-128)
I20260812 06:20:28.582203 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: LogGCOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.030s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:20:28.582629 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling UndoDeltaBlockGCOp(6b5600afaa354efcaf3933b33f537c83): 492 bytes on disk
I20260812 06:20:28.583103 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: UndoDeltaBlockGCOp(6b5600afaa354efcaf3933b33f537c83) 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:20:28.583590 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83): perf score=4.173312
I20260812 06:20:28.604012 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.020s	user 0.008s	sys 0.011s Metrics: {"bytes_written":6030801,"delete_count":0,"lbm_write_time_us":8689,"lbm_writes_lt_1ms":150,"reinsert_count":0,"update_count":735}
I20260812 06:20:28.604573 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83): perf score=1.196750
I20260812 06:20:28.615547 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":2174479,"delete_count":0,"lbm_write_time_us":3438,"lbm_writes_lt_1ms":56,"reinsert_count":0,"update_count":265}
I20260812 06:20:28.616273 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling MajorDeltaCompactionOp(6b5600afaa354efcaf3933b33f537c83): perf score=1.000000
I20260812 06:20:28.852072 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: MajorDeltaCompactionOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.236s	user 0.133s	sys 0.089s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979707,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1249,"lbm_read_time_us":15325,"lbm_reads_lt_1ms":774,"lbm_write_time_us":35913,"lbm_writes_lt_1ms":743,"mutex_wait_us":660,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":3072,"thread_start_us":84,"threads_started":1,"update_count":3500}
I20260812 06:20:28.853123 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83): perf score=18.063937
I20260812 06:20:28.926589 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.073s	user 0.020s	sys 0.041s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":29504,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:28.927145 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83): perf score=2.188937
I20260812 06:20:28.939199 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4358,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.939765 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling MajorDeltaCompactionOp(6b5600afaa354efcaf3933b33f537c83): perf score=1.000000
I20260812 06:20:29.140820 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: MajorDeltaCompactionOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.201s	user 0.142s	sys 0.059s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877105,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":258,"lbm_read_time_us":14026,"lbm_reads_lt_1ms":672,"lbm_write_time_us":34561,"lbm_writes_lt_1ms":643,"mutex_wait_us":76,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6784,"update_count":3000}
I20260812 06:20:29.141518 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83): perf score=14.095187
I20260812 06:20:29.202911 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.061s	user 0.025s	sys 0.021s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":21307,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:29.203573 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83): perf score=2.188937
I20260812 06:20:29.216169 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.012s	user 0.002s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4620,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.216708 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling MajorDeltaCompactionOp(6b5600afaa354efcaf3933b33f537c83): perf score=1.000000
I20260812 06:20:29.403355 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: MajorDeltaCompactionOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.186s	user 0.126s	sys 0.057s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":158,"lbm_read_time_us":14577,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28705,"lbm_writes_lt_1ms":543,"mutex_wait_us":43,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13824,"update_count":2500}
I20260812 06:20:29.404033 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83): perf score=14.095187
I20260812 06:20:29.460846 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.057s	user 0.023s	sys 0.028s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22341,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:29.461467 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83): perf score=2.188937
I20260812 06:20:29.474538 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.013s	user 0.000s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4703,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.475191 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling MajorDeltaCompactionOp(6b5600afaa354efcaf3933b33f537c83): perf score=1.000000
I20260812 06:20:29.662948 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: MajorDeltaCompactionOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.187s	user 0.110s	sys 0.073s 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":912,"lbm_read_time_us":13767,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30698,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":19968,"update_count":2500}
I20260812 06:20:29.663712 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83): perf score=14.095187
I20260812 06:20:29.732803 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.069s	user 0.040s	sys 0.026s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23403,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:29.733364 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83): perf score=2.188937
I20260812 06:20:29.744253 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4170,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.744761 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling MajorDeltaCompactionOp(6b5600afaa354efcaf3933b33f537c83): perf score=1.000000
I20260812 06:20:29.922943 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: MajorDeltaCompactionOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.178s	user 0.121s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":187,"lbm_read_time_us":12892,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30594,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9984,"update_count":2500}
I20260812 06:20:29.923755 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83): perf score=11.118625
I20260812 06:20:29.957618 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.033s	user 0.029s	sys 0.001s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":14055,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:29.958331 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83): perf score=2.188937
I20260812 06:20:29.992843 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.034s	user 0.012s	sys 0.010s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5597,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:29.993377 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83): perf score=2.188937
I20260812 06:20:30.004294 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4255,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:30.004908 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling FlushMRSOp(6b5600afaa354efcaf3933b33f537c83): perf score=1.000000
I20260812 06:20:30.035552 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: FlushMRSOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.030s	user 0.028s	sys 0.001s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":72,"dirs.run_cpu_time_us":277,"dirs.run_wall_time_us":1604,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1419,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:30.036331 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling UndoDeltaBlockGCOp(6b5600afaa354efcaf3933b33f537c83): 448 bytes on disk
I20260812 06:20:30.036936 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: UndoDeltaBlockGCOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":89,"lbm_reads_lt_1ms":4}
I20260812 06:20:30.037614 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling MajorDeltaCompactionOp(6b5600afaa354efcaf3933b33f537c83): perf score=1.000000
I20260812 06:20:30.218206 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: MajorDeltaCompactionOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.180s	user 0.120s	sys 0.060s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774801,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":212,"lbm_read_time_us":14194,"lbm_reads_lt_1ms":565,"lbm_write_time_us":29329,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6912,"update_count":2500}
I20260812 06:20:30.218962 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling LogGCOp(6b5600afaa354efcaf3933b33f537c83): free 121006700 bytes of WAL
I20260812 06:20:30.219235 12896 log_reader.cc:385] T 6b5600afaa354efcaf3933b33f537c83: removed 12 log segments from log reader
I20260812 06:20:30.219290 12896 log.cc:1079] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/6b5600afaa354efcaf3933b33f537c83/wal-000000027 (ops 129-133)
I20260812 06:20:30.219328 12896 log.cc:1079] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/6b5600afaa354efcaf3933b33f537c83/wal-000000028 (ops 134-138)
I20260812 06:20:30.219357 12896 log.cc:1079] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/6b5600afaa354efcaf3933b33f537c83/wal-000000029 (ops 139-143)
I20260812 06:20:30.219436 12896 log.cc:1079] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/6b5600afaa354efcaf3933b33f537c83/wal-000000030 (ops 144-148)
I20260812 06:20:30.219481 12896 log.cc:1079] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/6b5600afaa354efcaf3933b33f537c83/wal-000000031 (ops 149-153)
I20260812 06:20:30.219504 12896 log.cc:1079] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/6b5600afaa354efcaf3933b33f537c83/wal-000000032 (ops 154-158)
I20260812 06:20:30.219583 12896 log.cc:1079] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/6b5600afaa354efcaf3933b33f537c83/wal-000000033 (ops 159-163)
I20260812 06:20:30.219621 12896 log.cc:1079] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/6b5600afaa354efcaf3933b33f537c83/wal-000000034 (ops 164-168)
I20260812 06:20:30.219681 12896 log.cc:1079] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/6b5600afaa354efcaf3933b33f537c83/wal-000000035 (ops 169-172)
I20260812 06:20:30.219723 12896 log.cc:1079] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/6b5600afaa354efcaf3933b33f537c83/wal-000000036 (ops 173-177)
I20260812 06:20:30.219820 12896 log.cc:1079] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/6b5600afaa354efcaf3933b33f537c83/wal-000000037 (ops 178-182)
I20260812 06:20:30.219862 12896 log.cc:1079] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9: Deleting log segment in path: /tmp/dist-test-task2eQuEY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515619545971-12543-0/minicluster-data/ts-0-root/wals/6b5600afaa354efcaf3933b33f537c83/wal-000000038 (ops 183-187)
I20260812 06:20:30.250778 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: LogGCOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.032s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:20:30.251252 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83): perf score=14.095187
I20260812 06:20:30.298431 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.047s	user 0.026s	sys 0.017s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21381,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:30.298944 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83): perf score=2.188937
I20260812 06:20:30.329128 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.030s	user 0.009s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5454,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:30.329700 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83): perf score=2.188937
I20260812 06:20:30.340378 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: FlushDeltaMemStoresOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4213,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:30.341066 12973 maintenance_manager.cc:419] P 5422cc919a2f4993bc66732504c63ac9: Scheduling MajorDeltaCompactionOp(6b5600afaa354efcaf3933b33f537c83): perf score=1.000000
I20260812 06:20:30.422765 12543 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.079s	user 1.856s	sys 0.211s
I20260812 06:20:30.515529 12543 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.092s	user 0.002s	sys 0.000s
I20260812 06:20:30.516072 12543 tablet_server.cc:179] TabletServer@127.12.63.193:0 shutting down...
I20260812 06:20:30.543766 12896 maintenance_manager.cc:643] P 5422cc919a2f4993bc66732504c63ac9: MajorDeltaCompactionOp(6b5600afaa354efcaf3933b33f537c83) complete. Timing: real 0.202s	user 0.143s	sys 0.059s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877221,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":541,"lbm_read_time_us":14198,"lbm_reads_lt_1ms":669,"lbm_write_time_us":34216,"lbm_writes_lt_1ms":643,"mutex_wait_us":123,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6144,"update_count":3000}
I20260812 06:20:30.544808 12543 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:30.545094 12543 tablet_replica.cc:333] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9: stopping tablet replica
I20260812 06:20:30.545248 12543 raft_consensus.cc:2243] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:30.545480 12543 raft_consensus.cc:2272] T 6b5600afaa354efcaf3933b33f537c83 P 5422cc919a2f4993bc66732504c63ac9 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:30.561655 12543 tablet_server.cc:196] TabletServer@127.12.63.193:0 shutdown complete.
I20260812 06:20:30.600036 12543 master.cc:562] Master@127.12.63.254:46137 shutting down...
I20260812 06:20:30.603752 12543 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 9b1dd650c84f4e009264d5c4816e9678 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:30.603953 12543 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 9b1dd650c84f4e009264d5c4816e9678 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:30.604027 12543 tablet_replica.cc:333] T 00000000000000000000000000000000 P 9b1dd650c84f4e009264d5c4816e9678: stopping tablet replica
I20260812 06:20:30.616358 12543 master.cc:584] Master@127.12.63.254:46137 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5588 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11145 ms total)

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