[==========] 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:16:37.213716  4403 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.4.76.254:33765
I20260812 06:16:37.214671  4403 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:16:37.215211  4403 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:37.221501  4414 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:16:37.221645  4403 server_base.cc:1061] running on GCE node
W20260812 06:16:37.221769  4415 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:16:37.221778  4421 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:16:37.222306  4403 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:37.222395  4403 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:16:37.222424  4403 hybrid_clock.cc:648] HybridClock initialized: now 1786515397222423 us; error 0 us; skew 500 ppm
I20260812 06:16:37.224133  4403 webserver.cc:533] Webserver started at http://127.4.76.254:37557/ using document root <none> and password file <none>
I20260812 06:16:37.224619  4403 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:37.224673  4403 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:37.224867  4403 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:37.226441  4403 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397202067-4403-0/minicluster-data/master-0-root/instance:
uuid: "2a997bef32594f1e925b851978d3d484"
format_stamp: "Formatted at 2026-08-12 06:16:37 on dist-test-slave-7lbf"
I20260812 06:16:37.229727  4403 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:16:37.231753  4430 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:16:37.232684  4403 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:16:37.232795  4403 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397202067-4403-0/minicluster-data/master-0-root
uuid: "2a997bef32594f1e925b851978d3d484"
format_stamp: "Formatted at 2026-08-12 06:16:37 on dist-test-slave-7lbf"
I20260812 06:16:37.232910  4403 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397202067-4403-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397202067-4403-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397202067-4403-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:16:37.244225  4403 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:37.244761  4403 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:16:37.244911  4403 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:37.251818  4523 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.4.76.254:33765 every 8 connection(s)
I20260812 06:16:37.251824  4403 rpc_server.cc:307] RPC server started. Bound to: 127.4.76.254:33765
I20260812 06:16:37.253991  4524 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:16:37.259053  4524 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 2a997bef32594f1e925b851978d3d484: Bootstrap starting.
I20260812 06:16:37.261221  4524 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 2a997bef32594f1e925b851978d3d484: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:37.262056  4524 log.cc:826] T 00000000000000000000000000000000 P 2a997bef32594f1e925b851978d3d484: Log is configured to *not* fsync() on all Append() calls
I20260812 06:16:37.263566  4524 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 2a997bef32594f1e925b851978d3d484: No bootstrap required, opened a new log
I20260812 06:16:37.266139  4524 raft_consensus.cc:359] T 00000000000000000000000000000000 P 2a997bef32594f1e925b851978d3d484 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2a997bef32594f1e925b851978d3d484" member_type: VOTER }
I20260812 06:16:37.266285  4524 raft_consensus.cc:385] T 00000000000000000000000000000000 P 2a997bef32594f1e925b851978d3d484 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:37.266323  4524 raft_consensus.cc:740] T 00000000000000000000000000000000 P 2a997bef32594f1e925b851978d3d484 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 2a997bef32594f1e925b851978d3d484, State: Initialized, Role: FOLLOWER
I20260812 06:16:37.266804  4524 consensus_queue.cc:260] T 00000000000000000000000000000000 P 2a997bef32594f1e925b851978d3d484 [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: "2a997bef32594f1e925b851978d3d484" member_type: VOTER }
I20260812 06:16:37.266927  4524 raft_consensus.cc:399] T 00000000000000000000000000000000 P 2a997bef32594f1e925b851978d3d484 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:37.266968  4524 raft_consensus.cc:493] T 00000000000000000000000000000000 P 2a997bef32594f1e925b851978d3d484 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:37.267059  4524 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 2a997bef32594f1e925b851978d3d484 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:37.267735  4524 raft_consensus.cc:515] T 00000000000000000000000000000000 P 2a997bef32594f1e925b851978d3d484 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2a997bef32594f1e925b851978d3d484" member_type: VOTER }
I20260812 06:16:37.268115  4524 leader_election.cc:304] T 00000000000000000000000000000000 P 2a997bef32594f1e925b851978d3d484 [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: 2a997bef32594f1e925b851978d3d484; no voters: 
I20260812 06:16:37.268365  4524 leader_election.cc:290] T 00000000000000000000000000000000 P 2a997bef32594f1e925b851978d3d484 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:37.268478  4528 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 2a997bef32594f1e925b851978d3d484 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:37.268678  4528 raft_consensus.cc:697] T 00000000000000000000000000000000 P 2a997bef32594f1e925b851978d3d484 [term 1 LEADER]: Becoming Leader. State: Replica: 2a997bef32594f1e925b851978d3d484, State: Running, Role: LEADER
I20260812 06:16:37.269110  4528 consensus_queue.cc:237] T 00000000000000000000000000000000 P 2a997bef32594f1e925b851978d3d484 [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: "2a997bef32594f1e925b851978d3d484" member_type: VOTER }
I20260812 06:16:37.269264  4524 sys_catalog.cc:565] T 00000000000000000000000000000000 P 2a997bef32594f1e925b851978d3d484 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:37.270952  4532 sys_catalog.cc:455] T 00000000000000000000000000000000 P 2a997bef32594f1e925b851978d3d484 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 2a997bef32594f1e925b851978d3d484. Latest consensus state: current_term: 1 leader_uuid: "2a997bef32594f1e925b851978d3d484" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2a997bef32594f1e925b851978d3d484" member_type: VOTER } }
I20260812 06:16:37.271062  4532 sys_catalog.cc:458] T 00000000000000000000000000000000 P 2a997bef32594f1e925b851978d3d484 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:37.271308  4531 sys_catalog.cc:455] T 00000000000000000000000000000000 P 2a997bef32594f1e925b851978d3d484 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "2a997bef32594f1e925b851978d3d484" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2a997bef32594f1e925b851978d3d484" member_type: VOTER } }
I20260812 06:16:37.271376  4549 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:37.271389  4531 sys_catalog.cc:458] T 00000000000000000000000000000000 P 2a997bef32594f1e925b851978d3d484 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:37.271479  4403 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:16:37.273485  4549 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:37.277951  4549 catalog_manager.cc:1383] Generated new cluster ID: 718fb0e6014646f49117387740e5e212
I20260812 06:16:37.278003  4549 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:37.297062  4549 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:37.297951  4549 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:37.303930  4549 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 2a997bef32594f1e925b851978d3d484: Generated new TSK 0
I20260812 06:16:37.304520  4549 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:37.336694  4403 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:37.339398  4561 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:16:37.339613  4403 server_base.cc:1061] running on GCE node
W20260812 06:16:37.339622  4565 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:16:37.339444  4563 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:16:37.339948  4403 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:37.340018  4403 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:16:37.340040  4403 hybrid_clock.cc:648] HybridClock initialized: now 1786515397340040 us; error 0 us; skew 500 ppm
I20260812 06:16:37.340941  4403 webserver.cc:533] Webserver started at http://127.4.76.193:34453/ using document root <none> and password file <none>
I20260812 06:16:37.341113  4403 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:37.341173  4403 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:37.341248  4403 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:37.341741  4403 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397202067-4403-0/minicluster-data/ts-0-root/instance:
uuid: "e332324a707742a7b2b8b88ff9877a5f"
format_stamp: "Formatted at 2026-08-12 06:16:37 on dist-test-slave-7lbf"
I20260812 06:16:37.343559  4403 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:16:37.344599  4572 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:16:37.344856  4403 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:37.344935  4403 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397202067-4403-0/minicluster-data/ts-0-root
uuid: "e332324a707742a7b2b8b88ff9877a5f"
format_stamp: "Formatted at 2026-08-12 06:16:37 on dist-test-slave-7lbf"
I20260812 06:16:37.345005  4403 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397202067-4403-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397202067-4403-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397202067-4403-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:16:37.351094  4403 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:37.351501  4403 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:37.351986  4403 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:37.352892  4403 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:37.352955  4403 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:37.353029  4403 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:37.353060  4403 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:37.359576  4403 rpc_server.cc:307] RPC server started. Bound to: 127.4.76.193:39623
I20260812 06:16:37.359596  4687 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.4.76.193:39623 every 8 connection(s)
I20260812 06:16:37.369060  4689 heartbeater.cc:344] Connected to a master server at 127.4.76.254:33765
I20260812 06:16:37.369302  4689 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:37.369745  4689 heartbeater.cc:507] Master 127.4.76.254:33765 requested a full tablet report, sending...
I20260812 06:16:37.371059  4468 ts_manager.cc:194] Registered new tserver with Master: e332324a707742a7b2b8b88ff9877a5f (127.4.76.193:39623)
I20260812 06:16:37.371423  4403 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011186681s
I20260812 06:16:37.372274  4468 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:40534
I20260812 06:16:37.380350  4468 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:40548:
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:16:37.393966  4621 tablet_service.cc:1511] Processing CreateTablet for tablet d1f3279d779b46dc9ff9f8b9faea47cf (DEFAULT_TABLE table=heavy-update-compaction-test [id=3e24fa1c44ae4151944487acde8fab07]), partition=
I20260812 06:16:37.394366  4621 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet d1f3279d779b46dc9ff9f8b9faea47cf. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:37.396730  4713 tablet_bootstrap.cc:492] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f: Bootstrap starting.
I20260812 06:16:37.397861  4713 tablet_bootstrap.cc:654] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:37.399085  4713 tablet_bootstrap.cc:492] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f: No bootstrap required, opened a new log
I20260812 06:16:37.399195  4713 ts_tablet_manager.cc:1403] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:16:37.399943  4713 raft_consensus.cc:359] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e332324a707742a7b2b8b88ff9877a5f" member_type: VOTER last_known_addr { host: "127.4.76.193" port: 39623 } }
I20260812 06:16:37.400067  4713 raft_consensus.cc:385] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:37.400107  4713 raft_consensus.cc:740] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: e332324a707742a7b2b8b88ff9877a5f, State: Initialized, Role: FOLLOWER
I20260812 06:16:37.400231  4713 consensus_queue.cc:260] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f [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: "e332324a707742a7b2b8b88ff9877a5f" member_type: VOTER last_known_addr { host: "127.4.76.193" port: 39623 } }
I20260812 06:16:37.400326  4713 raft_consensus.cc:399] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:37.400367  4713 raft_consensus.cc:493] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:37.400424  4713 raft_consensus.cc:3060] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:37.401324  4713 raft_consensus.cc:515] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e332324a707742a7b2b8b88ff9877a5f" member_type: VOTER last_known_addr { host: "127.4.76.193" port: 39623 } }
I20260812 06:16:37.401480  4713 leader_election.cc:304] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f [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: e332324a707742a7b2b8b88ff9877a5f; no voters: 
I20260812 06:16:37.401708  4713 leader_election.cc:290] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:37.401813  4716 raft_consensus.cc:2804] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:37.402084  4716 raft_consensus.cc:697] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f [term 1 LEADER]: Becoming Leader. State: Replica: e332324a707742a7b2b8b88ff9877a5f, State: Running, Role: LEADER
I20260812 06:16:37.402117  4713 ts_tablet_manager.cc:1434] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:16:37.402274  4716 consensus_queue.cc:237] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f [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: "e332324a707742a7b2b8b88ff9877a5f" member_type: VOTER last_known_addr { host: "127.4.76.193" port: 39623 } }
I20260812 06:16:37.402629  4689 heartbeater.cc:499] Master 127.4.76.254:33765 was elected leader, sending a full tablet report...
I20260812 06:16:37.404943  4468 catalog_manager.cc:5719] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f reported cstate change: term changed from 0 to 1, leader changed from <none> to e332324a707742a7b2b8b88ff9877a5f (127.4.76.193). New cstate: current_term: 1 leader_uuid: "e332324a707742a7b2b8b88ff9877a5f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e332324a707742a7b2b8b88ff9877a5f" member_type: VOTER last_known_addr { host: "127.4.76.193" port: 39623 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:37.473585  4403 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.059s	user 0.020s	sys 0.010s
I20260812 06:16:37.610832  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling FlushMRSOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=19.054940
I20260812 06:16:37.806232  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: FlushMRSOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.195s	user 0.157s	sys 0.035s Metrics: {"bytes_written":16409901,"cfile_init":1,"compiler_manager_pool.queue_time_us":243,"delete_count":0,"dirs.queue_time_us":55,"dirs.run_cpu_time_us":219,"dirs.run_wall_time_us":990,"drs_written":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4,"lbm_write_time_us":48377,"lbm_writes_lt_1ms":857,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":133,"threads_started":1,"update_count":2000}
I20260812 06:16:37.807466  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling LogGCOp(d1f3279d779b46dc9ff9f8b9faea47cf): free 20743880 bytes of WAL
I20260812 06:16:37.807862  4583 log_reader.cc:385] T d1f3279d779b46dc9ff9f8b9faea47cf: removed 2 log segments from log reader
I20260812 06:16:37.807997  4583 log.cc:1079] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/d1f3279d779b46dc9ff9f8b9faea47cf/wal-000000001 (ops 1-6)
I20260812 06:16:37.808112  4583 log.cc:1079] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/d1f3279d779b46dc9ff9f8b9faea47cf/wal-000000002 (ops 7-11)
I20260812 06:16:37.812494  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: LogGCOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.005s	user 0.000s	sys 0.002s Metrics: {"spinlock_wait_cycles":14080}
I20260812 06:16:37.812816  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling UndoDeltaBlockGCOp(d1f3279d779b46dc9ff9f8b9faea47cf): 16411396 bytes on disk
I20260812 06:16:37.813429  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: UndoDeltaBlockGCOp(d1f3279d779b46dc9ff9f8b9faea47cf) 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:16:37.813902  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=3.181125
I20260812 06:16:37.826607  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.013s	user 0.004s	sys 0.007s Metrics: {"bytes_written":5251342,"delete_count":0,"lbm_write_time_us":4906,"lbm_writes_lt_1ms":131,"reinsert_count":0,"update_count":640}
I20260812 06:16:37.826979  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=1.196750
I20260812 06:16:37.834574  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.007s	user 0.006s	sys 0.000s Metrics: {"bytes_written":2953955,"delete_count":0,"lbm_write_time_us":2697,"lbm_writes_lt_1ms":75,"reinsert_count":0,"update_count":360}
I20260812 06:16:37.835070  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling MajorDeltaCompactionOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=1.000000
I20260812 06:16:38.020167  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: MajorDeltaCompactionOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.185s	user 0.128s	sys 0.048s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877192,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":225,"lbm_read_time_us":12484,"lbm_reads_lt_1ms":669,"lbm_write_time_us":32031,"lbm_writes_lt_1ms":643,"mutex_wait_us":33,"peak_mem_usage":75542472,"reinsert_count":0,"thread_start_us":278,"threads_started":5,"update_count":3000}
I20260812 06:16:38.020610  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=14.095187
I20260812 06:16:38.076202  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.055s	user 0.032s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20244,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:38.076761  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=2.188937
I20260812 06:16:38.087958  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4214,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:38.088702  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling MajorDeltaCompactionOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=1.000000
I20260812 06:16:38.244700  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: MajorDeltaCompactionOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.156s	user 0.122s	sys 0.028s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"lbm_read_time_us":9820,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28283,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":2500}
I20260812 06:16:38.245163  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=11.118625
I20260812 06:16:38.283596  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.038s	user 0.020s	sys 0.016s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":15440,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:38.286263  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=2.188937
I20260812 06:16:38.302058  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.016s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4109,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:38.302573  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling MajorDeltaCompactionOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=1.000000
I20260812 06:16:38.439406  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: MajorDeltaCompactionOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.137s	user 0.092s	sys 0.044s 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":528,"lbm_read_time_us":7252,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24418,"lbm_writes_lt_1ms":443,"mutex_wait_us":1,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:16:38.439986  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=10.126437
I20260812 06:16:38.471700  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.032s	user 0.009s	sys 0.021s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13614,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:38.472191  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=2.188937
I20260812 06:16:38.488068  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.016s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5979,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:38.488698  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling MajorDeltaCompactionOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=1.000000
I20260812 06:16:38.605221  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: MajorDeltaCompactionOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.116s	user 0.096s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":184,"lbm_read_time_us":9365,"lbm_reads_lt_1ms":464,"lbm_write_time_us":21009,"lbm_writes_lt_1ms":443,"mutex_wait_us":28,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":41984,"update_count":2000}
I20260812 06:16:38.605734  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=10.126437
I20260812 06:16:38.648350  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.042s	user 0.028s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17202,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:38.648850  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=2.188937
I20260812 06:16:38.658958  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3686,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:38.659504  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling MajorDeltaCompactionOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=1.000000
I20260812 06:16:38.774063  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: MajorDeltaCompactionOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.114s	user 0.098s	sys 0.016s 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":930,"lbm_read_time_us":7351,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21934,"lbm_writes_lt_1ms":443,"mutex_wait_us":262,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5248,"update_count":2000}
I20260812 06:16:38.774610  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=10.126437
I20260812 06:16:38.819591  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.045s	user 0.023s	sys 0.015s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14048,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:38.820107  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=2.188937
I20260812 06:16:38.830080  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3722,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:38.830508  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling MajorDeltaCompactionOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=1.000000
I20260812 06:16:38.962428  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: MajorDeltaCompactionOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.132s	user 0.094s	sys 0.035s 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":176,"lbm_read_time_us":9251,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21293,"lbm_writes_lt_1ms":443,"mutex_wait_us":2,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:16:38.963014  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=10.126437
I20260812 06:16:39.006752  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.044s	user 0.015s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13482,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:39.007272  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=2.188937
I20260812 06:16:39.022781  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5546,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:39.023353  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling FlushMRSOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=1.000000
I20260812 06:16:39.052142  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: FlushMRSOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.029s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":51,"dirs.run_cpu_time_us":156,"dirs.run_wall_time_us":1203,"drs_written":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1646,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:16:39.052999  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling LogGCOp(d1f3279d779b46dc9ff9f8b9faea47cf): free 121006435 bytes of WAL
I20260812 06:16:39.053233  4583 log_reader.cc:385] T d1f3279d779b46dc9ff9f8b9faea47cf: removed 12 log segments from log reader
I20260812 06:16:39.053278  4583 log.cc:1079] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/d1f3279d779b46dc9ff9f8b9faea47cf/wal-000000003 (ops 12-16)
I20260812 06:16:39.053309  4583 log.cc:1079] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/d1f3279d779b46dc9ff9f8b9faea47cf/wal-000000004 (ops 17-21)
I20260812 06:16:39.053340  4583 log.cc:1079] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/d1f3279d779b46dc9ff9f8b9faea47cf/wal-000000005 (ops 22-26)
I20260812 06:16:39.053372  4583 log.cc:1079] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/d1f3279d779b46dc9ff9f8b9faea47cf/wal-000000006 (ops 27-31)
I20260812 06:16:39.053403  4583 log.cc:1079] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/d1f3279d779b46dc9ff9f8b9faea47cf/wal-000000007 (ops 32-36)
I20260812 06:16:39.053435  4583 log.cc:1079] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/d1f3279d779b46dc9ff9f8b9faea47cf/wal-000000008 (ops 37-40)
I20260812 06:16:39.053465  4583 log.cc:1079] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/d1f3279d779b46dc9ff9f8b9faea47cf/wal-000000009 (ops 41-45)
I20260812 06:16:39.053508  4583 log.cc:1079] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/d1f3279d779b46dc9ff9f8b9faea47cf/wal-000000010 (ops 46-50)
I20260812 06:16:39.053565  4583 log.cc:1079] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/d1f3279d779b46dc9ff9f8b9faea47cf/wal-000000011 (ops 51-55)
I20260812 06:16:39.053597  4583 log.cc:1079] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/d1f3279d779b46dc9ff9f8b9faea47cf/wal-000000012 (ops 56-60)
I20260812 06:16:39.053627  4583 log.cc:1079] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/d1f3279d779b46dc9ff9f8b9faea47cf/wal-000000013 (ops 61-65)
I20260812 06:16:39.053658  4583 log.cc:1079] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/d1f3279d779b46dc9ff9f8b9faea47cf/wal-000000014 (ops 66-70)
I20260812 06:16:39.074496  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: LogGCOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.021s	user 0.001s	sys 0.019s Metrics: {}
I20260812 06:16:39.074913  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling UndoDeltaBlockGCOp(d1f3279d779b46dc9ff9f8b9faea47cf): 481 bytes on disk
I20260812 06:16:39.075479  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: UndoDeltaBlockGCOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4}
I20260812 06:16:39.075961  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=3.181125
I20260812 06:16:39.096616  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.021s	user 0.009s	sys 0.007s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4089,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:39.097091  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=2.188937
I20260812 06:16:39.111198  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5102,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:39.111737  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling MajorDeltaCompactionOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=1.000000
I20260812 06:16:39.308807  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: MajorDeltaCompactionOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.197s	user 0.118s	sys 0.068s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877329,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":657,"lbm_read_time_us":14326,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33651,"lbm_writes_lt_1ms":643,"mutex_wait_us":56,"peak_mem_usage":75542472,"reinsert_count":0,"thread_start_us":69,"threads_started":1,"update_count":3000}
I20260812 06:16:39.309401  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=14.095187
I20260812 06:16:39.363423  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.054s	user 0.023s	sys 0.027s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19461,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:39.364004  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=2.188937
I20260812 06:16:39.376056  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4617,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:39.376540  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling MajorDeltaCompactionOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=1.000000
I20260812 06:16:39.555553  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: MajorDeltaCompactionOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.179s	user 0.105s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":518,"lbm_read_time_us":12708,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30605,"lbm_writes_lt_1ms":543,"mutex_wait_us":299,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4480,"update_count":2500}
I20260812 06:16:39.556025  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=14.095187
I20260812 06:16:39.601363  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.045s	user 0.017s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17846,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:39.601917  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=2.188937
I20260812 06:16:39.623631  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.022s	user 0.004s	sys 0.015s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5763,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:39.624167  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling MajorDeltaCompactionOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=1.000000
I20260812 06:16:39.798098  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: MajorDeltaCompactionOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.174s	user 0.116s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":780,"lbm_read_time_us":11119,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28647,"lbm_writes_lt_1ms":543,"mutex_wait_us":57,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:16:39.798661  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=11.118625
I20260812 06:16:39.840905  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.042s	user 0.028s	sys 0.009s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17460,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:39.841464  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=2.188937
I20260812 06:16:39.860563  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.019s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4905,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:39.861042  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=2.188937
I20260812 06:16:39.870123  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3254,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:39.870571  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling MajorDeltaCompactionOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=1.000000
I20260812 06:16:40.044027  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: MajorDeltaCompactionOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.173s	user 0.104s	sys 0.055s 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":902,"lbm_read_time_us":9126,"lbm_reads_lt_1ms":573,"lbm_write_time_us":28704,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2500}
I20260812 06:16:40.044760  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=14.095187
I20260812 06:16:40.089763  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.045s	user 0.026s	sys 0.019s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20196,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:40.090273  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=2.188937
I20260812 06:16:40.104314  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5337,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:40.104907  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling MajorDeltaCompactionOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=1.000000
I20260812 06:16:40.258517  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: MajorDeltaCompactionOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.153s	user 0.121s	sys 0.021s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":967,"lbm_read_time_us":9881,"lbm_reads_lt_1ms":564,"lbm_write_time_us":26616,"lbm_writes_lt_1ms":543,"mutex_wait_us":274,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11392,"update_count":2500}
I20260812 06:16:40.259023  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=14.095187
I20260812 06:16:40.310426  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.051s	user 0.028s	sys 0.016s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20141,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:40.310997  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=2.188937
I20260812 06:16:40.321099  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3685,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:40.321812  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling MajorDeltaCompactionOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=1.000000
I20260812 06:16:40.455627  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: MajorDeltaCompactionOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.134s	user 0.104s	sys 0.027s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":824,"lbm_read_time_us":8721,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26598,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":2500}
I20260812 06:16:40.456233  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=11.118625
I20260812 06:16:40.488534  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.032s	user 0.023s	sys 0.005s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13083,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:40.489109  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=2.188937
I20260812 06:16:40.505191  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.016s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4384,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:40.505688  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=2.188937
I20260812 06:16:40.514741  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.009s	user 0.003s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3316,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:40.515302  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling FlushMRSOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=1.000000
I20260812 06:16:40.549866  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: FlushMRSOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.034s	user 0.034s	sys 0.000s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":54,"dirs.run_cpu_time_us":202,"dirs.run_wall_time_us":1468,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1698,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:16:40.550773  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling LogGCOp(d1f3279d779b46dc9ff9f8b9faea47cf): free 136275199 bytes of WAL
I20260812 06:16:40.551023  4583 log_reader.cc:385] T d1f3279d779b46dc9ff9f8b9faea47cf: removed 13 log segments from log reader
I20260812 06:16:40.551070  4583 log.cc:1079] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/d1f3279d779b46dc9ff9f8b9faea47cf/wal-000000015 (ops 71-75)
I20260812 06:16:40.551110  4583 log.cc:1079] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/d1f3279d779b46dc9ff9f8b9faea47cf/wal-000000016 (ops 76-80)
I20260812 06:16:40.551143  4583 log.cc:1079] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/d1f3279d779b46dc9ff9f8b9faea47cf/wal-000000017 (ops 81-85)
I20260812 06:16:40.551175  4583 log.cc:1079] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/d1f3279d779b46dc9ff9f8b9faea47cf/wal-000000018 (ops 86-90)
I20260812 06:16:40.551205  4583 log.cc:1079] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/d1f3279d779b46dc9ff9f8b9faea47cf/wal-000000019 (ops 91-95)
I20260812 06:16:40.551236  4583 log.cc:1079] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/d1f3279d779b46dc9ff9f8b9faea47cf/wal-000000020 (ops 96-100)
I20260812 06:16:40.551262  4583 log.cc:1079] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/d1f3279d779b46dc9ff9f8b9faea47cf/wal-000000021 (ops 101-104)
I20260812 06:16:40.551301  4583 log.cc:1079] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/d1f3279d779b46dc9ff9f8b9faea47cf/wal-000000022 (ops 105-109)
I20260812 06:16:40.551332  4583 log.cc:1079] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/d1f3279d779b46dc9ff9f8b9faea47cf/wal-000000023 (ops 110-114)
I20260812 06:16:40.551362  4583 log.cc:1079] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/d1f3279d779b46dc9ff9f8b9faea47cf/wal-000000024 (ops 115-119)
I20260812 06:16:40.551393  4583 log.cc:1079] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/d1f3279d779b46dc9ff9f8b9faea47cf/wal-000000025 (ops 120-124)
I20260812 06:16:40.551424  4583 log.cc:1079] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/d1f3279d779b46dc9ff9f8b9faea47cf/wal-000000026 (ops 125-129)
I20260812 06:16:40.551452  4583 log.cc:1079] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/d1f3279d779b46dc9ff9f8b9faea47cf/wal-000000027 (ops 130-134)
I20260812 06:16:40.574422  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: LogGCOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.023s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:16:40.574817  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling UndoDeltaBlockGCOp(d1f3279d779b46dc9ff9f8b9faea47cf): 493 bytes on disk
I20260812 06:16:40.575394  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: UndoDeltaBlockGCOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4}
I20260812 06:16:40.575913  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=4.173312
I20260812 06:16:40.593405  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.017s	user 0.007s	sys 0.008s Metrics: {"bytes_written":5497488,"delete_count":0,"lbm_write_time_us":7075,"lbm_writes_lt_1ms":137,"reinsert_count":0,"update_count":670}
I20260812 06:16:40.593896  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=1.196750
I20260812 06:16:40.602815  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.009s	user 0.007s	sys 0.000s Metrics: {"bytes_written":2707805,"delete_count":0,"lbm_write_time_us":2911,"lbm_writes_lt_1ms":69,"reinsert_count":0,"update_count":330}
I20260812 06:16:40.603264  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling MajorDeltaCompactionOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=1.000000
I20260812 06:16:40.795718  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: MajorDeltaCompactionOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.192s	user 0.158s	sys 0.032s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979830,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":640,"lbm_read_time_us":12957,"lbm_reads_lt_1ms":771,"lbm_write_time_us":39603,"lbm_writes_lt_1ms":743,"mutex_wait_us":363,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":12544,"thread_start_us":81,"threads_started":1,"update_count":3500}
I20260812 06:16:40.796310  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=15.087375
I20260812 06:16:40.843984  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.048s	user 0.025s	sys 0.020s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":20899,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:16:40.844645  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=2.188937
I20260812 06:16:40.867355  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.022s	user 0.003s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4554,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:40.867842  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=2.188937
I20260812 06:16:40.878494  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.010s	user 0.001s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3942,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:40.878996  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling MajorDeltaCompactionOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=1.000000
I20260812 06:16:41.033854  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: MajorDeltaCompactionOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.155s	user 0.110s	sys 0.044s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877206,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":864,"lbm_read_time_us":10106,"lbm_reads_lt_1ms":673,"lbm_write_time_us":31780,"lbm_writes_lt_1ms":643,"mutex_wait_us":291,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":13184,"update_count":3000}
I20260812 06:16:41.034307  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=14.095187
I20260812 06:16:41.080376  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.046s	user 0.031s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18656,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:41.080888  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=2.188937
I20260812 06:16:41.090966  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3737,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:41.091606  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling MajorDeltaCompactionOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=1.000000
I20260812 06:16:41.248525  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: MajorDeltaCompactionOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.157s	user 0.106s	sys 0.040s 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":229,"lbm_read_time_us":9488,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27645,"lbm_writes_lt_1ms":543,"mutex_wait_us":82,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:16:41.249255  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=14.095187
I20260812 06:16:41.288179  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.039s	user 0.028s	sys 0.008s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":16945,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:41.288672  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling MajorDeltaCompactionOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=1.000000
I20260812 06:16:41.420919  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: MajorDeltaCompactionOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.132s	user 0.104s	sys 0.028s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672158,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":252,"lbm_read_time_us":8048,"lbm_reads_lt_1ms":467,"lbm_write_time_us":24410,"lbm_writes_lt_1ms":443,"mutex_wait_us":71,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:16:41.421456  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=10.126437
I20260812 06:16:41.451110  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.029s	user 0.019s	sys 0.009s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12754,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:41.451644  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=2.188937
I20260812 06:16:41.463726  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4645,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:41.464438  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling MajorDeltaCompactionOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=1.000000
I20260812 06:16:41.581202  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: MajorDeltaCompactionOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.117s	user 0.088s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":123,"lbm_read_time_us":8684,"lbm_reads_lt_1ms":464,"lbm_write_time_us":20621,"lbm_writes_lt_1ms":443,"mutex_wait_us":28,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":19840,"update_count":2000}
I20260812 06:16:41.581750  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=10.126437
I20260812 06:16:41.620622  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.039s	user 0.021s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13835,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:41.621182  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=2.188937
I20260812 06:16:41.631143  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3659,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:41.631798  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling MajorDeltaCompactionOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=1.000000
I20260812 06:16:41.750396  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: MajorDeltaCompactionOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.118s	user 0.095s	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":183,"lbm_read_time_us":8383,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22391,"lbm_writes_lt_1ms":443,"mutex_wait_us":39,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14848,"update_count":2000}
I20260812 06:16:41.750968  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=10.126437
I20260812 06:16:41.796262  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.045s	user 0.018s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13997,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:41.796833  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=2.188937
I20260812 06:16:41.811877  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.015s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5499,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:41.812469  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling FlushMRSOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=1.000000
I20260812 06:16:41.838352  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: FlushMRSOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.026s	user 0.019s	sys 0.006s Metrics: {"bytes_written":1193507,"cfile_init":1,"dirs.queue_time_us":35,"dirs.run_cpu_time_us":199,"dirs.run_wall_time_us":1512,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1434,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:16:41.838989  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling LogGCOp(d1f3279d779b46dc9ff9f8b9faea47cf): free 121006699 bytes of WAL
I20260812 06:16:41.839206  4583 log_reader.cc:385] T d1f3279d779b46dc9ff9f8b9faea47cf: removed 12 log segments from log reader
I20260812 06:16:41.839253  4583 log.cc:1079] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/d1f3279d779b46dc9ff9f8b9faea47cf/wal-000000028 (ops 135-139)
I20260812 06:16:41.839283  4583 log.cc:1079] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/d1f3279d779b46dc9ff9f8b9faea47cf/wal-000000029 (ops 140-144)
I20260812 06:16:41.839313  4583 log.cc:1079] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/d1f3279d779b46dc9ff9f8b9faea47cf/wal-000000030 (ops 145-149)
I20260812 06:16:41.839344  4583 log.cc:1079] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/d1f3279d779b46dc9ff9f8b9faea47cf/wal-000000031 (ops 150-154)
I20260812 06:16:41.839375  4583 log.cc:1079] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/d1f3279d779b46dc9ff9f8b9faea47cf/wal-000000032 (ops 155-159)
I20260812 06:16:41.839408  4583 log.cc:1079] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/d1f3279d779b46dc9ff9f8b9faea47cf/wal-000000033 (ops 160-164)
I20260812 06:16:41.839442  4583 log.cc:1079] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/d1f3279d779b46dc9ff9f8b9faea47cf/wal-000000034 (ops 165-169)
I20260812 06:16:41.839473  4583 log.cc:1079] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/d1f3279d779b46dc9ff9f8b9faea47cf/wal-000000035 (ops 170-174)
I20260812 06:16:41.839506  4583 log.cc:1079] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/d1f3279d779b46dc9ff9f8b9faea47cf/wal-000000036 (ops 175-178)
I20260812 06:16:41.839540  4583 log.cc:1079] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/d1f3279d779b46dc9ff9f8b9faea47cf/wal-000000037 (ops 179-183)
I20260812 06:16:41.839570  4583 log.cc:1079] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/d1f3279d779b46dc9ff9f8b9faea47cf/wal-000000038 (ops 184-188)
I20260812 06:16:41.839602  4583 log.cc:1079] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/d1f3279d779b46dc9ff9f8b9faea47cf/wal-000000039 (ops 189-193)
I20260812 06:16:41.860064  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: LogGCOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.021s	user 0.000s	sys 0.018s Metrics: {}
I20260812 06:16:41.860451  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling UndoDeltaBlockGCOp(d1f3279d779b46dc9ff9f8b9faea47cf): 462 bytes on disk
I20260812 06:16:41.860908  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: UndoDeltaBlockGCOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:16:41.861482  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=3.181125
I20260812 06:16:41.881206  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.020s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":6970,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:41.881716  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=2.188937
I20260812 06:16:41.890684  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: FlushDeltaMemStoresOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.009s	user 0.007s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3181,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:41.891124  4691 maintenance_manager.cc:419] P e332324a707742a7b2b8b88ff9877a5f: Scheduling MajorDeltaCompactionOp(d1f3279d779b46dc9ff9f8b9faea47cf): perf score=1.000000
I20260812 06:16:41.971247  4403 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.498s	user 1.617s	sys 0.149s
I20260812 06:16:42.061371  4403 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.090s	user 0.001s	sys 0.000s
I20260812 06:16:42.061995  4403 tablet_server.cc:179] TabletServer@127.4.76.193:0 shutting down...
I20260812 06:16:42.068516  4583 maintenance_manager.cc:643] P e332324a707742a7b2b8b88ff9877a5f: MajorDeltaCompactionOp(d1f3279d779b46dc9ff9f8b9faea47cf) complete. Timing: real 0.177s	user 0.150s	sys 0.024s 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":791,"dirs.run_cpu_time_us":991,"dirs.run_wall_time_us":5901,"lbm_read_time_us":12129,"lbm_reads_lt_1ms":670,"lbm_write_time_us":37747,"lbm_writes_lt_1ms":643,"mutex_wait_us":22,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":15488,"update_count":3000}
I20260812 06:16:42.069073  4403 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:16:42.069496  4403 tablet_replica.cc:333] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f: stopping tablet replica
I20260812 06:16:42.069747  4403 raft_consensus.cc:2243] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:42.069991  4403 raft_consensus.cc:2272] T d1f3279d779b46dc9ff9f8b9faea47cf P e332324a707742a7b2b8b88ff9877a5f [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:42.086928  4403 tablet_server.cc:196] TabletServer@127.4.76.193:0 shutdown complete.
I20260812 06:16:42.115335  4403 master.cc:562] Master@127.4.76.254:33765 shutting down...
I20260812 06:16:42.118392  4403 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 2a997bef32594f1e925b851978d3d484 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:42.118572  4403 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 2a997bef32594f1e925b851978d3d484 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:42.118650  4403 tablet_replica.cc:333] T 00000000000000000000000000000000 P 2a997bef32594f1e925b851978d3d484: stopping tablet replica
I20260812 06:16:42.130846  4403 master.cc:584] Master@127.4.76.254:33765 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (4984 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:16:42.197979  4403 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.4.76.254:37433
I20260812 06:16:42.198371  4403 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:42.200384  4750 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:16:42.200439  4745 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:16:42.200563  4403 server_base.cc:1061] running on GCE node
W20260812 06:16:42.200496  4743 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:16:42.200791  4403 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:42.200835  4403 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:16:42.200848  4403 hybrid_clock.cc:648] HybridClock initialized: now 1786515402200849 us; error 0 us; skew 500 ppm
I20260812 06:16:42.201682  4403 webserver.cc:533] Webserver started at http://127.4.76.254:40381/ using document root <none> and password file <none>
I20260812 06:16:42.201836  4403 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:42.201884  4403 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:42.201963  4403 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:42.202322  4403 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397202067-4403-0/minicluster-data/master-0-root/instance:
uuid: "dc182d3f00b04ff8b8cb04e6551669c2"
format_stamp: "Formatted at 2026-08-12 06:16:42 on dist-test-slave-7lbf"
I20260812 06:16:42.203835  4403 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:16:42.204672  4757 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:16:42.204892  4403 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:42.204959  4403 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397202067-4403-0/minicluster-data/master-0-root
uuid: "dc182d3f00b04ff8b8cb04e6551669c2"
format_stamp: "Formatted at 2026-08-12 06:16:42 on dist-test-slave-7lbf"
I20260812 06:16:42.205030  4403 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397202067-4403-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397202067-4403-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397202067-4403-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:16:42.216660  4403 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:42.217031  4403 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:42.221493  4403 rpc_server.cc:307] RPC server started. Bound to: 127.4.76.254:37433
I20260812 06:16:42.235538  4860 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.4.76.254:37433 every 8 connection(s)
I20260812 06:16:42.236025  4866 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:16:42.237866  4866 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P dc182d3f00b04ff8b8cb04e6551669c2: Bootstrap starting.
I20260812 06:16:42.238637  4866 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P dc182d3f00b04ff8b8cb04e6551669c2: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:42.239624  4866 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P dc182d3f00b04ff8b8cb04e6551669c2: No bootstrap required, opened a new log
I20260812 06:16:42.240033  4866 raft_consensus.cc:359] T 00000000000000000000000000000000 P dc182d3f00b04ff8b8cb04e6551669c2 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "dc182d3f00b04ff8b8cb04e6551669c2" member_type: VOTER }
I20260812 06:16:42.240121  4866 raft_consensus.cc:385] T 00000000000000000000000000000000 P dc182d3f00b04ff8b8cb04e6551669c2 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:42.240152  4866 raft_consensus.cc:740] T 00000000000000000000000000000000 P dc182d3f00b04ff8b8cb04e6551669c2 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: dc182d3f00b04ff8b8cb04e6551669c2, State: Initialized, Role: FOLLOWER
I20260812 06:16:42.240394  4866 consensus_queue.cc:260] T 00000000000000000000000000000000 P dc182d3f00b04ff8b8cb04e6551669c2 [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: "dc182d3f00b04ff8b8cb04e6551669c2" member_type: VOTER }
I20260812 06:16:42.240484  4873 raft_consensus.cc:493] T 00000000000000000000000000000000 P dc182d3f00b04ff8b8cb04e6551669c2 [term 0 FOLLOWER]: Starting pre-election (no leader contacted us within the election timeout)
I20260812 06:16:42.240574  4873 raft_consensus.cc:515] T 00000000000000000000000000000000 P dc182d3f00b04ff8b8cb04e6551669c2 [term 0 FOLLOWER]: Starting pre-election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "dc182d3f00b04ff8b8cb04e6551669c2" member_type: VOTER }
I20260812 06:16:42.240729  4873 leader_election.cc:304] T 00000000000000000000000000000000 P dc182d3f00b04ff8b8cb04e6551669c2 [CANDIDATE]: Term 1 pre-election: Election decided. Result: candidate won. Election summary: received 1 responses out of 1 voters: 1 yes votes; 0 no votes. yes voters: dc182d3f00b04ff8b8cb04e6551669c2; no voters: 
I20260812 06:16:42.240746  4866 raft_consensus.cc:399] T 00000000000000000000000000000000 P dc182d3f00b04ff8b8cb04e6551669c2 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:42.240808  4866 raft_consensus.cc:493] T 00000000000000000000000000000000 P dc182d3f00b04ff8b8cb04e6551669c2 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:42.240859  4866 raft_consensus.cc:3060] T 00000000000000000000000000000000 P dc182d3f00b04ff8b8cb04e6551669c2 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:42.240965  4873 leader_election.cc:290] T 00000000000000000000000000000000 P dc182d3f00b04ff8b8cb04e6551669c2 [CANDIDATE]: Term 1 pre-election: Requested pre-vote from peers 
I20260812 06:16:42.241628  4866 raft_consensus.cc:515] T 00000000000000000000000000000000 P dc182d3f00b04ff8b8cb04e6551669c2 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "dc182d3f00b04ff8b8cb04e6551669c2" member_type: VOTER }
I20260812 06:16:42.241743  4866 leader_election.cc:304] T 00000000000000000000000000000000 P dc182d3f00b04ff8b8cb04e6551669c2 [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: dc182d3f00b04ff8b8cb04e6551669c2; no voters: 
I20260812 06:16:42.241796  4876 raft_consensus.cc:2764] T 00000000000000000000000000000000 P dc182d3f00b04ff8b8cb04e6551669c2 [term 1 FOLLOWER]: Leader pre-election decision vote started in defunct term 0: won
I20260812 06:16:42.241835  4866 leader_election.cc:290] T 00000000000000000000000000000000 P dc182d3f00b04ff8b8cb04e6551669c2 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:42.241989  4873 raft_consensus.cc:2804] T 00000000000000000000000000000000 P dc182d3f00b04ff8b8cb04e6551669c2 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:42.242115  4873 raft_consensus.cc:697] T 00000000000000000000000000000000 P dc182d3f00b04ff8b8cb04e6551669c2 [term 1 LEADER]: Becoming Leader. State: Replica: dc182d3f00b04ff8b8cb04e6551669c2, State: Running, Role: LEADER
I20260812 06:16:42.242249  4866 sys_catalog.cc:565] T 00000000000000000000000000000000 P dc182d3f00b04ff8b8cb04e6551669c2 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:42.242260  4873 consensus_queue.cc:237] T 00000000000000000000000000000000 P dc182d3f00b04ff8b8cb04e6551669c2 [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: "dc182d3f00b04ff8b8cb04e6551669c2" member_type: VOTER }
I20260812 06:16:42.242641  4876 sys_catalog.cc:455] T 00000000000000000000000000000000 P dc182d3f00b04ff8b8cb04e6551669c2 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "dc182d3f00b04ff8b8cb04e6551669c2" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "dc182d3f00b04ff8b8cb04e6551669c2" member_type: VOTER } }
I20260812 06:16:42.242728  4876 sys_catalog.cc:458] T 00000000000000000000000000000000 P dc182d3f00b04ff8b8cb04e6551669c2 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:42.242702  4877 sys_catalog.cc:455] T 00000000000000000000000000000000 P dc182d3f00b04ff8b8cb04e6551669c2 [sys.catalog]: SysCatalogTable state changed. Reason: New leader dc182d3f00b04ff8b8cb04e6551669c2. Latest consensus state: current_term: 1 leader_uuid: "dc182d3f00b04ff8b8cb04e6551669c2" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "dc182d3f00b04ff8b8cb04e6551669c2" member_type: VOTER } }
I20260812 06:16:42.242817  4877 sys_catalog.cc:458] T 00000000000000000000000000000000 P dc182d3f00b04ff8b8cb04e6551669c2 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:42.242988  4880 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:42.243841  4880 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:42.244123  4403 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:16:42.245548  4880 catalog_manager.cc:1383] Generated new cluster ID: a5aa8072b9db4601b96ed8904dddd1ae
I20260812 06:16:42.245602  4880 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:42.252624  4880 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:42.253163  4880 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:42.263466  4880 catalog_manager.cc:6092] T 00000000000000000000000000000000 P dc182d3f00b04ff8b8cb04e6551669c2: Generated new TSK 0
I20260812 06:16:42.263638  4880 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:42.276420  4403 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:42.278281  4909 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:16:42.278343  4913 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:16:42.278442  4910 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:16:42.278358  4403 server_base.cc:1061] running on GCE node
I20260812 06:16:42.278730  4403 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:42.278772  4403 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:16:42.278792  4403 hybrid_clock.cc:648] HybridClock initialized: now 1786515402278792 us; error 0 us; skew 500 ppm
I20260812 06:16:42.279537  4403 webserver.cc:533] Webserver started at http://127.4.76.193:41609/ using document root <none> and password file <none>
I20260812 06:16:42.279690  4403 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:42.279747  4403 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:42.279815  4403 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:42.280172  4403 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397202067-4403-0/minicluster-data/ts-0-root/instance:
uuid: "8664b96aa0c04a3b9afe4298b1e475bb"
format_stamp: "Formatted at 2026-08-12 06:16:42 on dist-test-slave-7lbf"
I20260812 06:16:42.281587  4403 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:16:42.282429  4922 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:16:42.282635  4403 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:42.282699  4403 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397202067-4403-0/minicluster-data/ts-0-root
uuid: "8664b96aa0c04a3b9afe4298b1e475bb"
format_stamp: "Formatted at 2026-08-12 06:16:42 on dist-test-slave-7lbf"
I20260812 06:16:42.282763  4403 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397202067-4403-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397202067-4403-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397202067-4403-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:16:42.294523  4403 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:42.294899  4403 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:42.295194  4403 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:42.295646  4403 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:42.295686  4403 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:42.295728  4403 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:42.295756  4403 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:42.300083  4403 rpc_server.cc:307] RPC server started. Bound to: 127.4.76.193:45945
I20260812 06:16:42.300137  5028 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.4.76.193:45945 every 8 connection(s)
I20260812 06:16:42.308243  5029 heartbeater.cc:344] Connected to a master server at 127.4.76.254:37433
I20260812 06:16:42.308362  5029 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:42.308594  5029 heartbeater.cc:507] Master 127.4.76.254:37433 requested a full tablet report, sending...
I20260812 06:16:42.309233  4790 ts_manager.cc:194] Registered new tserver with Master: 8664b96aa0c04a3b9afe4298b1e475bb (127.4.76.193:45945)
I20260812 06:16:42.309254  4403 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.008778552s
I20260812 06:16:42.310006  4790 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:49464
I20260812 06:16:42.316352  4790 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:49476:
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:16:42.325017  4971 tablet_service.cc:1511] Processing CreateTablet for tablet f6cbcdffd2554ce49c9b22f8c01303e0 (DEFAULT_TABLE table=heavy-update-compaction-test [id=8b4f6a686f66491580c40e0a30ae059d]), partition=
I20260812 06:16:42.325297  4971 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet f6cbcdffd2554ce49c9b22f8c01303e0. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:42.327625  5056 tablet_bootstrap.cc:492] T f6cbcdffd2554ce49c9b22f8c01303e0 P 8664b96aa0c04a3b9afe4298b1e475bb: Bootstrap starting.
I20260812 06:16:42.328508  5056 tablet_bootstrap.cc:654] T f6cbcdffd2554ce49c9b22f8c01303e0 P 8664b96aa0c04a3b9afe4298b1e475bb: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:42.329487  5056 tablet_bootstrap.cc:492] T f6cbcdffd2554ce49c9b22f8c01303e0 P 8664b96aa0c04a3b9afe4298b1e475bb: No bootstrap required, opened a new log
I20260812 06:16:42.329595  5056 ts_tablet_manager.cc:1403] T f6cbcdffd2554ce49c9b22f8c01303e0 P 8664b96aa0c04a3b9afe4298b1e475bb: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:16:42.329998  5056 raft_consensus.cc:359] T f6cbcdffd2554ce49c9b22f8c01303e0 P 8664b96aa0c04a3b9afe4298b1e475bb [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8664b96aa0c04a3b9afe4298b1e475bb" member_type: VOTER last_known_addr { host: "127.4.76.193" port: 45945 } }
I20260812 06:16:42.330103  5056 raft_consensus.cc:385] T f6cbcdffd2554ce49c9b22f8c01303e0 P 8664b96aa0c04a3b9afe4298b1e475bb [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:42.330147  5056 raft_consensus.cc:740] T f6cbcdffd2554ce49c9b22f8c01303e0 P 8664b96aa0c04a3b9afe4298b1e475bb [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 8664b96aa0c04a3b9afe4298b1e475bb, State: Initialized, Role: FOLLOWER
I20260812 06:16:42.330273  5056 consensus_queue.cc:260] T f6cbcdffd2554ce49c9b22f8c01303e0 P 8664b96aa0c04a3b9afe4298b1e475bb [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: "8664b96aa0c04a3b9afe4298b1e475bb" member_type: VOTER last_known_addr { host: "127.4.76.193" port: 45945 } }
I20260812 06:16:42.330358  5056 raft_consensus.cc:399] T f6cbcdffd2554ce49c9b22f8c01303e0 P 8664b96aa0c04a3b9afe4298b1e475bb [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:42.330392  5056 raft_consensus.cc:493] T f6cbcdffd2554ce49c9b22f8c01303e0 P 8664b96aa0c04a3b9afe4298b1e475bb [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:42.330440  5056 raft_consensus.cc:3060] T f6cbcdffd2554ce49c9b22f8c01303e0 P 8664b96aa0c04a3b9afe4298b1e475bb [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:42.393743  5056 raft_consensus.cc:515] T f6cbcdffd2554ce49c9b22f8c01303e0 P 8664b96aa0c04a3b9afe4298b1e475bb [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8664b96aa0c04a3b9afe4298b1e475bb" member_type: VOTER last_known_addr { host: "127.4.76.193" port: 45945 } }
I20260812 06:16:42.393972  5056 leader_election.cc:304] T f6cbcdffd2554ce49c9b22f8c01303e0 P 8664b96aa0c04a3b9afe4298b1e475bb [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: 8664b96aa0c04a3b9afe4298b1e475bb; no voters: 
I20260812 06:16:42.394227  5056 leader_election.cc:290] T f6cbcdffd2554ce49c9b22f8c01303e0 P 8664b96aa0c04a3b9afe4298b1e475bb [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:42.394439  5062 raft_consensus.cc:2804] T f6cbcdffd2554ce49c9b22f8c01303e0 P 8664b96aa0c04a3b9afe4298b1e475bb [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:42.394630  5056 ts_tablet_manager.cc:1434] T f6cbcdffd2554ce49c9b22f8c01303e0 P 8664b96aa0c04a3b9afe4298b1e475bb: Time spent starting tablet: real 0.065s	user 0.000s	sys 0.002s
I20260812 06:16:42.394663  5029 heartbeater.cc:499] Master 127.4.76.254:37433 was elected leader, sending a full tablet report...
I20260812 06:16:42.394734  5062 raft_consensus.cc:697] T f6cbcdffd2554ce49c9b22f8c01303e0 P 8664b96aa0c04a3b9afe4298b1e475bb [term 1 LEADER]: Becoming Leader. State: Replica: 8664b96aa0c04a3b9afe4298b1e475bb, State: Running, Role: LEADER
I20260812 06:16:42.394894  5062 consensus_queue.cc:237] T f6cbcdffd2554ce49c9b22f8c01303e0 P 8664b96aa0c04a3b9afe4298b1e475bb [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: "8664b96aa0c04a3b9afe4298b1e475bb" member_type: VOTER last_known_addr { host: "127.4.76.193" port: 45945 } }
I20260812 06:16:42.396562  4790 catalog_manager.cc:5719] T f6cbcdffd2554ce49c9b22f8c01303e0 P 8664b96aa0c04a3b9afe4298b1e475bb reported cstate change: term changed from 0 to 1, leader changed from <none> to 8664b96aa0c04a3b9afe4298b1e475bb (127.4.76.193). New cstate: current_term: 1 leader_uuid: "8664b96aa0c04a3b9afe4298b1e475bb" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8664b96aa0c04a3b9afe4298b1e475bb" member_type: VOTER last_known_addr { host: "127.4.76.193" port: 45945 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:42.471617  4403 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.052s	user 0.015s	sys 0.008s
I20260812 06:16:42.551149  5031 maintenance_manager.cc:419] P 8664b96aa0c04a3b9afe4298b1e475bb: Scheduling FlushMRSOp(f6cbcdffd2554ce49c9b22f8c01303e0): perf score=10.125253
I20260812 06:16:42.695215  4930 maintenance_manager.cc:643] P 8664b96aa0c04a3b9afe4298b1e475bb: FlushMRSOp(f6cbcdffd2554ce49c9b22f8c01303e0) complete. Timing: real 0.144s	user 0.075s	sys 0.031s Metrics: {"bytes_written":8492251,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":57,"drs_written":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4,"lbm_write_time_us":21475,"lbm_writes_lt_1ms":464,"peak_mem_usage":0,"reinsert_count":0,"rows_written":102,"spinlock_wait_cycles":7424,"update_count":1035}
I20260812 06:16:42.695936  5031 maintenance_manager.cc:419] P 8664b96aa0c04a3b9afe4298b1e475bb: Scheduling FlushDeltaMemStoresOp(f6cbcdffd2554ce49c9b22f8c01303e0): perf score=5.165500
I20260812 06:16:42.794616  4930 maintenance_manager.cc:643] P 8664b96aa0c04a3b9afe4298b1e475bb: FlushDeltaMemStoresOp(f6cbcdffd2554ce49c9b22f8c01303e0) complete. Timing: real 0.098s	user 0.012s	sys 0.007s Metrics: {"bytes_written":7056405,"delete_count":0,"lbm_write_time_us":7782,"lbm_writes_lt_1ms":175,"reinsert_count":0,"update_count":860}
I20260812 06:16:42.795234  5031 maintenance_manager.cc:419] P 8664b96aa0c04a3b9afe4298b1e475bb: Scheduling LogGCOp(f6cbcdffd2554ce49c9b22f8c01303e0): free 8725963 bytes of WAL
I20260812 06:16:42.795524  4930 log_reader.cc:385] T f6cbcdffd2554ce49c9b22f8c01303e0: removed 1 log segments from log reader
I20260812 06:16:42.795629  4930 log.cc:1079] T f6cbcdffd2554ce49c9b22f8c01303e0 P 8664b96aa0c04a3b9afe4298b1e475bb: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/f6cbcdffd2554ce49c9b22f8c01303e0/wal-000000001 (ops 1-6)
I20260812 06:16:42.798430  4930 maintenance_manager.cc:643] P 8664b96aa0c04a3b9afe4298b1e475bb: LogGCOp(f6cbcdffd2554ce49c9b22f8c01303e0) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:16:42.798834  5031 maintenance_manager.cc:419] P 8664b96aa0c04a3b9afe4298b1e475bb: Scheduling UndoDeltaBlockGCOp(f6cbcdffd2554ce49c9b22f8c01303e0): 8206537 bytes on disk
I20260812 06:16:42.799451  4930 maintenance_manager.cc:643] P 8664b96aa0c04a3b9afe4298b1e475bb: UndoDeltaBlockGCOp(f6cbcdffd2554ce49c9b22f8c01303e0) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4}
I20260812 06:16:42.800035  5031 maintenance_manager.cc:419] P 8664b96aa0c04a3b9afe4298b1e475bb: Scheduling FlushDeltaMemStoresOp(f6cbcdffd2554ce49c9b22f8c01303e0): perf score=7.149875
I20260812 06:16:42.893510  4930 maintenance_manager.cc:643] P 8664b96aa0c04a3b9afe4298b1e475bb: FlushDeltaMemStoresOp(f6cbcdffd2554ce49c9b22f8c01303e0) complete. Timing: real 0.093s	user 0.021s	sys 0.008s Metrics: {"bytes_written":9066590,"delete_count":0,"lbm_write_time_us":12596,"lbm_writes_lt_1ms":224,"reinsert_count":0,"update_count":1105}
I20260812 06:16:42.894117  5031 maintenance_manager.cc:419] P 8664b96aa0c04a3b9afe4298b1e475bb: Scheduling FlushDeltaMemStoresOp(f6cbcdffd2554ce49c9b22f8c01303e0): perf score=6.157687
I20260812 06:16:43.004076  4930 maintenance_manager.cc:643] P 8664b96aa0c04a3b9afe4298b1e475bb: FlushDeltaMemStoresOp(f6cbcdffd2554ce49c9b22f8c01303e0) complete. Timing: real 0.110s	user 0.014s	sys 0.010s Metrics: {"bytes_written":8205079,"delete_count":0,"lbm_write_time_us":8145,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:43.004670  5031 maintenance_manager.cc:419] P 8664b96aa0c04a3b9afe4298b1e475bb: Scheduling FlushDeltaMemStoresOp(f6cbcdffd2554ce49c9b22f8c01303e0): perf score=10.126437
I20260812 06:16:43.103801  4930 maintenance_manager.cc:643] P 8664b96aa0c04a3b9afe4298b1e475bb: FlushDeltaMemStoresOp(f6cbcdffd2554ce49c9b22f8c01303e0) complete. Timing: real 0.099s	user 0.022s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13865,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:43.104243  5031 maintenance_manager.cc:419] P 8664b96aa0c04a3b9afe4298b1e475bb: Scheduling FlushDeltaMemStoresOp(f6cbcdffd2554ce49c9b22f8c01303e0): perf score=6.157687
I20260812 06:16:43.204353  4930 maintenance_manager.cc:643] P 8664b96aa0c04a3b9afe4298b1e475bb: FlushDeltaMemStoresOp(f6cbcdffd2554ce49c9b22f8c01303e0) complete. Timing: real 0.100s	user 0.008s	sys 0.010s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":8032,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:43.204859  5031 maintenance_manager.cc:419] P 8664b96aa0c04a3b9afe4298b1e475bb: Scheduling FlushDeltaMemStoresOp(f6cbcdffd2554ce49c9b22f8c01303e0): perf score=6.157687
I20260812 06:16:43.305050  4930 maintenance_manager.cc:643] P 8664b96aa0c04a3b9afe4298b1e475bb: FlushDeltaMemStoresOp(f6cbcdffd2554ce49c9b22f8c01303e0) complete. Timing: real 0.100s	user 0.007s	sys 0.011s Metrics: {"bytes_written":8205077,"delete_count":0,"lbm_write_time_us":7995,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:43.305593  5031 maintenance_manager.cc:419] P 8664b96aa0c04a3b9afe4298b1e475bb: Scheduling FlushDeltaMemStoresOp(f6cbcdffd2554ce49c9b22f8c01303e0): perf score=10.126437
I20260812 06:16:43.408397  4930 maintenance_manager.cc:643] P 8664b96aa0c04a3b9afe4298b1e475bb: FlushDeltaMemStoresOp(f6cbcdffd2554ce49c9b22f8c01303e0) complete. Timing: real 0.103s	user 0.015s	sys 0.021s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16558,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:43.408892  5031 maintenance_manager.cc:419] P 8664b96aa0c04a3b9afe4298b1e475bb: Scheduling FlushDeltaMemStoresOp(f6cbcdffd2554ce49c9b22f8c01303e0): perf score=6.157687
I20260812 06:16:43.505008  4930 maintenance_manager.cc:643] P 8664b96aa0c04a3b9afe4298b1e475bb: FlushDeltaMemStoresOp(f6cbcdffd2554ce49c9b22f8c01303e0) complete. Timing: real 0.096s	user 0.020s	sys 0.004s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":10620,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:43.505806  5031 maintenance_manager.cc:419] P 8664b96aa0c04a3b9afe4298b1e475bb: Scheduling FlushDeltaMemStoresOp(f6cbcdffd2554ce49c9b22f8c01303e0): perf score=6.157687
I20260812 06:16:43.603308  4930 maintenance_manager.cc:643] P 8664b96aa0c04a3b9afe4298b1e475bb: FlushDeltaMemStoresOp(f6cbcdffd2554ce49c9b22f8c01303e0) complete. Timing: real 0.097s	user 0.018s	sys 0.001s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":8177,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:43.603863  5031 maintenance_manager.cc:419] P 8664b96aa0c04a3b9afe4298b1e475bb: Scheduling FlushDeltaMemStoresOp(f6cbcdffd2554ce49c9b22f8c01303e0): perf score=10.126437
I20260812 06:16:43.704602  4930 maintenance_manager.cc:643] P 8664b96aa0c04a3b9afe4298b1e475bb: FlushDeltaMemStoresOp(f6cbcdffd2554ce49c9b22f8c01303e0) complete. Timing: real 0.101s	user 0.025s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16882,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:43.705204  5031 maintenance_manager.cc:419] P 8664b96aa0c04a3b9afe4298b1e475bb: Scheduling FlushDeltaMemStoresOp(f6cbcdffd2554ce49c9b22f8c01303e0): perf score=6.157687
I20260812 06:16:43.807145  4930 maintenance_manager.cc:643] P 8664b96aa0c04a3b9afe4298b1e475bb: FlushDeltaMemStoresOp(f6cbcdffd2554ce49c9b22f8c01303e0) complete. Timing: real 0.102s	user 0.011s	sys 0.012s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":10060,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:43.807891  5031 maintenance_manager.cc:419] P 8664b96aa0c04a3b9afe4298b1e475bb: Scheduling FlushDeltaMemStoresOp(f6cbcdffd2554ce49c9b22f8c01303e0): perf score=8.142062
I20260812 06:16:43.909694  4930 maintenance_manager.cc:643] P 8664b96aa0c04a3b9afe4298b1e475bb: FlushDeltaMemStoresOp(f6cbcdffd2554ce49c9b22f8c01303e0) complete. Timing: real 0.102s	user 0.020s	sys 0.005s Metrics: {"bytes_written":9517852,"delete_count":0,"lbm_write_time_us":9307,"lbm_writes_lt_1ms":235,"reinsert_count":0,"update_count":1160}
I20260812 06:16:43.910450  5031 maintenance_manager.cc:419] P 8664b96aa0c04a3b9afe4298b1e475bb: Scheduling FlushDeltaMemStoresOp(f6cbcdffd2554ce49c9b22f8c01303e0): perf score=9.134250
I20260812 06:16:44.008687  4930 maintenance_manager.cc:643] P 8664b96aa0c04a3b9afe4298b1e475bb: FlushDeltaMemStoresOp(f6cbcdffd2554ce49c9b22f8c01303e0) complete. Timing: real 0.098s	user 0.022s	sys 0.015s Metrics: {"bytes_written":10994718,"delete_count":0,"lbm_write_time_us":17191,"lbm_writes_lt_1ms":271,"reinsert_count":0,"update_count":1340}
I20260812 06:16:44.009450  5031 maintenance_manager.cc:419] P 8664b96aa0c04a3b9afe4298b1e475bb: Scheduling FlushDeltaMemStoresOp(f6cbcdffd2554ce49c9b22f8c01303e0): perf score=6.157687
I20260812 06:16:44.101992  4930 maintenance_manager.cc:643] P 8664b96aa0c04a3b9afe4298b1e475bb: FlushDeltaMemStoresOp(f6cbcdffd2554ce49c9b22f8c01303e0) complete. Timing: real 0.092s	user 0.012s	sys 0.017s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":12175,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:44.103363  5031 maintenance_manager.cc:419] P 8664b96aa0c04a3b9afe4298b1e475bb: Scheduling FlushDeltaMemStoresOp(f6cbcdffd2554ce49c9b22f8c01303e0): perf score=6.157687
I20260812 06:16:44.201222  4930 maintenance_manager.cc:643] P 8664b96aa0c04a3b9afe4298b1e475bb: FlushDeltaMemStoresOp(f6cbcdffd2554ce49c9b22f8c01303e0) complete. Timing: real 0.098s	user 0.019s	sys 0.007s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":11648,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:44.201952  5031 maintenance_manager.cc:419] P 8664b96aa0c04a3b9afe4298b1e475bb: Scheduling FlushDeltaMemStoresOp(f6cbcdffd2554ce49c9b22f8c01303e0): perf score=7.149875
I20260812 06:16:44.303314  4930 maintenance_manager.cc:643] P 8664b96aa0c04a3b9afe4298b1e475bb: FlushDeltaMemStoresOp(f6cbcdffd2554ce49c9b22f8c01303e0) complete. Timing: real 0.101s	user 0.010s	sys 0.009s Metrics: {"bytes_written":8943513,"delete_count":0,"lbm_write_time_us":8375,"lbm_writes_lt_1ms":221,"reinsert_count":0,"update_count":1090}
I20260812 06:16:44.303966  5031 maintenance_manager.cc:419] P 8664b96aa0c04a3b9afe4298b1e475bb: Scheduling FlushDeltaMemStoresOp(f6cbcdffd2554ce49c9b22f8c01303e0): perf score=10.126437
I20260812 06:16:44.407714  4930 maintenance_manager.cc:643] P 8664b96aa0c04a3b9afe4298b1e475bb: FlushDeltaMemStoresOp(f6cbcdffd2554ce49c9b22f8c01303e0) complete. Timing: real 0.103s	user 0.008s	sys 0.018s Metrics: {"bytes_written":11569066,"delete_count":0,"lbm_write_time_us":11317,"lbm_writes_lt_1ms":285,"reinsert_count":0,"update_count":1410}
I20260812 06:16:44.408239  5031 maintenance_manager.cc:419] P 8664b96aa0c04a3b9afe4298b1e475bb: Scheduling FlushDeltaMemStoresOp(f6cbcdffd2554ce49c9b22f8c01303e0): perf score=10.126437
I20260812 06:16:44.507117  4930 maintenance_manager.cc:643] P 8664b96aa0c04a3b9afe4298b1e475bb: FlushDeltaMemStoresOp(f6cbcdffd2554ce49c9b22f8c01303e0) complete. Timing: real 0.099s	user 0.028s	sys 0.006s Metrics: {"bytes_written":11569060,"delete_count":0,"lbm_write_time_us":15460,"lbm_writes_lt_1ms":285,"reinsert_count":0,"update_count":1410}
I20260812 06:16:44.507622  5031 maintenance_manager.cc:419] P 8664b96aa0c04a3b9afe4298b1e475bb: Scheduling FlushDeltaMemStoresOp(f6cbcdffd2554ce49c9b22f8c01303e0): perf score=7.149875
I20260812 06:16:44.605958  4930 maintenance_manager.cc:643] P 8664b96aa0c04a3b9afe4298b1e475bb: FlushDeltaMemStoresOp(f6cbcdffd2554ce49c9b22f8c01303e0) complete. Timing: real 0.098s	user 0.019s	sys 0.004s Metrics: {"bytes_written":8943515,"delete_count":0,"lbm_write_time_us":9370,"lbm_writes_lt_1ms":221,"reinsert_count":0,"update_count":1090}
I20260812 06:16:44.606472  5031 maintenance_manager.cc:419] P 8664b96aa0c04a3b9afe4298b1e475bb: Scheduling FlushDeltaMemStoresOp(f6cbcdffd2554ce49c9b22f8c01303e0): perf score=7.149875
I20260812 06:16:44.704151  4930 maintenance_manager.cc:643] P 8664b96aa0c04a3b9afe4298b1e475bb: FlushDeltaMemStoresOp(f6cbcdffd2554ce49c9b22f8c01303e0) complete. Timing: real 0.098s	user 0.018s	sys 0.001s Metrics: {"bytes_written":8615322,"delete_count":0,"lbm_write_time_us":8178,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:16:44.704627  5031 maintenance_manager.cc:419] P 8664b96aa0c04a3b9afe4298b1e475bb: Scheduling FlushDeltaMemStoresOp(f6cbcdffd2554ce49c9b22f8c01303e0): perf score=10.126437
I20260812 06:16:44.808866  4930 maintenance_manager.cc:643] P 8664b96aa0c04a3b9afe4298b1e475bb: FlushDeltaMemStoresOp(f6cbcdffd2554ce49c9b22f8c01303e0) complete. Timing: real 0.104s	user 0.019s	sys 0.011s Metrics: {"bytes_written":11897250,"delete_count":0,"lbm_write_time_us":12579,"lbm_writes_lt_1ms":293,"reinsert_count":0,"update_count":1450}
I20260812 06:16:44.809549  5031 maintenance_manager.cc:419] P 8664b96aa0c04a3b9afe4298b1e475bb: Scheduling FlushDeltaMemStoresOp(f6cbcdffd2554ce49c9b22f8c01303e0): perf score=7.149875
I20260812 06:16:44.902699  4930 maintenance_manager.cc:643] P 8664b96aa0c04a3b9afe4298b1e475bb: FlushDeltaMemStoresOp(f6cbcdffd2554ce49c9b22f8c01303e0) complete. Timing: real 0.093s	user 0.006s	sys 0.012s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":7975,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:16:44.903273  5031 maintenance_manager.cc:419] P 8664b96aa0c04a3b9afe4298b1e475bb: Scheduling FlushDeltaMemStoresOp(f6cbcdffd2554ce49c9b22f8c01303e0): perf score=7.149875
I20260812 06:16:44.930866  4930 maintenance_manager.cc:643] P 8664b96aa0c04a3b9afe4298b1e475bb: FlushDeltaMemStoresOp(f6cbcdffd2554ce49c9b22f8c01303e0) complete. Timing: real 0.027s	user 0.018s	sys 0.008s Metrics: {"bytes_written":8738395,"delete_count":0,"lbm_write_time_us":11601,"lbm_writes_lt_1ms":216,"reinsert_count":0,"update_count":1065}
I20260812 06:16:44.931363  5031 maintenance_manager.cc:419] P 8664b96aa0c04a3b9afe4298b1e475bb: Scheduling FlushDeltaMemStoresOp(f6cbcdffd2554ce49c9b22f8c01303e0): perf score=1.196750
I20260812 06:16:44.989869  4930 maintenance_manager.cc:643] P 8664b96aa0c04a3b9afe4298b1e475bb: FlushDeltaMemStoresOp(f6cbcdffd2554ce49c9b22f8c01303e0) complete. Timing: real 0.058s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3159080,"delete_count":0,"lbm_write_time_us":3735,"lbm_writes_lt_1ms":80,"reinsert_count":0,"update_count":385}
I20260812 06:16:44.990447  5031 maintenance_manager.cc:419] P 8664b96aa0c04a3b9afe4298b1e475bb: Scheduling FlushDeltaMemStoresOp(f6cbcdffd2554ce49c9b22f8c01303e0): perf score=3.181125
I20260812 06:16:45.007597  4930 maintenance_manager.cc:643] P 8664b96aa0c04a3b9afe4298b1e475bb: FlushDeltaMemStoresOp(f6cbcdffd2554ce49c9b22f8c01303e0) complete. Timing: real 0.017s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":4005,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:45.008153  5031 maintenance_manager.cc:419] P 8664b96aa0c04a3b9afe4298b1e475bb: Scheduling FlushDeltaMemStoresOp(f6cbcdffd2554ce49c9b22f8c01303e0): perf score=2.188937
I20260812 06:16:45.022261  4930 maintenance_manager.cc:643] P 8664b96aa0c04a3b9afe4298b1e475bb: FlushDeltaMemStoresOp(f6cbcdffd2554ce49c9b22f8c01303e0) complete. Timing: real 0.014s	user 0.004s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5002,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:45.022907  5031 maintenance_manager.cc:419] P 8664b96aa0c04a3b9afe4298b1e475bb: Scheduling FlushMRSOp(f6cbcdffd2554ce49c9b22f8c01303e0): perf score=1.195565
I20260812 06:16:45.058771  4930 maintenance_manager.cc:643] P 8664b96aa0c04a3b9afe4298b1e475bb: FlushMRSOp(f6cbcdffd2554ce49c9b22f8c01303e0) complete. Timing: real 0.036s	user 0.030s	sys 0.004s Metrics: {"bytes_written":2381962,"cfile_init":1,"dirs.queue_time_us":203,"dirs.run_cpu_time_us":203,"dirs.run_wall_time_us":1393,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2183,"lbm_writes_lt_1ms":44,"peak_mem_usage":0,"rows_written":58,"spinlock_wait_cycles":1920,"thread_start_us":93,"threads_started":1}
I20260812 06:16:45.059464  5031 maintenance_manager.cc:419] P 8664b96aa0c04a3b9afe4298b1e475bb: Scheduling LogGCOp(f6cbcdffd2554ce49c9b22f8c01303e0): free 236949668 bytes of WAL
I20260812 06:16:45.059717  4930 log_reader.cc:385] T f6cbcdffd2554ce49c9b22f8c01303e0: removed 23 log segments from log reader
I20260812 06:16:45.059765  4930 log.cc:1079] T f6cbcdffd2554ce49c9b22f8c01303e0 P 8664b96aa0c04a3b9afe4298b1e475bb: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/f6cbcdffd2554ce49c9b22f8c01303e0/wal-000000002 (ops 7-11)
I20260812 06:16:45.059793  4930 log.cc:1079] T f6cbcdffd2554ce49c9b22f8c01303e0 P 8664b96aa0c04a3b9afe4298b1e475bb: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/f6cbcdffd2554ce49c9b22f8c01303e0/wal-000000003 (ops 12-16)
I20260812 06:16:45.059810  4930 log.cc:1079] T f6cbcdffd2554ce49c9b22f8c01303e0 P 8664b96aa0c04a3b9afe4298b1e475bb: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/f6cbcdffd2554ce49c9b22f8c01303e0/wal-000000004 (ops 17-21)
I20260812 06:16:45.059840  4930 log.cc:1079] T f6cbcdffd2554ce49c9b22f8c01303e0 P 8664b96aa0c04a3b9afe4298b1e475bb: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/f6cbcdffd2554ce49c9b22f8c01303e0/wal-000000005 (ops 22-26)
I20260812 06:16:45.059871  4930 log.cc:1079] T f6cbcdffd2554ce49c9b22f8c01303e0 P 8664b96aa0c04a3b9afe4298b1e475bb: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/f6cbcdffd2554ce49c9b22f8c01303e0/wal-000000006 (ops 27-31)
I20260812 06:16:45.059943  4930 log.cc:1079] T f6cbcdffd2554ce49c9b22f8c01303e0 P 8664b96aa0c04a3b9afe4298b1e475bb: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/f6cbcdffd2554ce49c9b22f8c01303e0/wal-000000007 (ops 32-36)
I20260812 06:16:45.059971  4930 log.cc:1079] T f6cbcdffd2554ce49c9b22f8c01303e0 P 8664b96aa0c04a3b9afe4298b1e475bb: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/f6cbcdffd2554ce49c9b22f8c01303e0/wal-000000008 (ops 37-40)
I20260812 06:16:45.060004  4930 log.cc:1079] T f6cbcdffd2554ce49c9b22f8c01303e0 P 8664b96aa0c04a3b9afe4298b1e475bb: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/f6cbcdffd2554ce49c9b22f8c01303e0/wal-000000009 (ops 41-45)
I20260812 06:16:45.060034  4930 log.cc:1079] T f6cbcdffd2554ce49c9b22f8c01303e0 P 8664b96aa0c04a3b9afe4298b1e475bb: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/f6cbcdffd2554ce49c9b22f8c01303e0/wal-000000010 (ops 46-50)
I20260812 06:16:45.060065  4930 log.cc:1079] T f6cbcdffd2554ce49c9b22f8c01303e0 P 8664b96aa0c04a3b9afe4298b1e475bb: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/f6cbcdffd2554ce49c9b22f8c01303e0/wal-000000011 (ops 51-55)
I20260812 06:16:45.060096  4930 log.cc:1079] T f6cbcdffd2554ce49c9b22f8c01303e0 P 8664b96aa0c04a3b9afe4298b1e475bb: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/f6cbcdffd2554ce49c9b22f8c01303e0/wal-000000012 (ops 56-60)
I20260812 06:16:45.060127  4930 log.cc:1079] T f6cbcdffd2554ce49c9b22f8c01303e0 P 8664b96aa0c04a3b9afe4298b1e475bb: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/f6cbcdffd2554ce49c9b22f8c01303e0/wal-000000013 (ops 61-65)
I20260812 06:16:45.060158  4930 log.cc:1079] T f6cbcdffd2554ce49c9b22f8c01303e0 P 8664b96aa0c04a3b9afe4298b1e475bb: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/f6cbcdffd2554ce49c9b22f8c01303e0/wal-000000014 (ops 66-70)
I20260812 06:16:45.060187  4930 log.cc:1079] T f6cbcdffd2554ce49c9b22f8c01303e0 P 8664b96aa0c04a3b9afe4298b1e475bb: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/f6cbcdffd2554ce49c9b22f8c01303e0/wal-000000015 (ops 71-75)
I20260812 06:16:45.060217  4930 log.cc:1079] T f6cbcdffd2554ce49c9b22f8c01303e0 P 8664b96aa0c04a3b9afe4298b1e475bb: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/f6cbcdffd2554ce49c9b22f8c01303e0/wal-000000016 (ops 76-80)
I20260812 06:16:45.060247  4930 log.cc:1079] T f6cbcdffd2554ce49c9b22f8c01303e0 P 8664b96aa0c04a3b9afe4298b1e475bb: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/f6cbcdffd2554ce49c9b22f8c01303e0/wal-000000017 (ops 81-85)
I20260812 06:16:45.060277  4930 log.cc:1079] T f6cbcdffd2554ce49c9b22f8c01303e0 P 8664b96aa0c04a3b9afe4298b1e475bb: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/f6cbcdffd2554ce49c9b22f8c01303e0/wal-000000018 (ops 86-90)
I20260812 06:16:45.060307  4930 log.cc:1079] T f6cbcdffd2554ce49c9b22f8c01303e0 P 8664b96aa0c04a3b9afe4298b1e475bb: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/f6cbcdffd2554ce49c9b22f8c01303e0/wal-000000019 (ops 91-95)
I20260812 06:16:45.060338  4930 log.cc:1079] T f6cbcdffd2554ce49c9b22f8c01303e0 P 8664b96aa0c04a3b9afe4298b1e475bb: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/f6cbcdffd2554ce49c9b22f8c01303e0/wal-000000020 (ops 96-100)
I20260812 06:16:45.060369  4930 log.cc:1079] T f6cbcdffd2554ce49c9b22f8c01303e0 P 8664b96aa0c04a3b9afe4298b1e475bb: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/f6cbcdffd2554ce49c9b22f8c01303e0/wal-000000021 (ops 101-105)
I20260812 06:16:45.060400  4930 log.cc:1079] T f6cbcdffd2554ce49c9b22f8c01303e0 P 8664b96aa0c04a3b9afe4298b1e475bb: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/f6cbcdffd2554ce49c9b22f8c01303e0/wal-000000022 (ops 106-110)
I20260812 06:16:45.060431  4930 log.cc:1079] T f6cbcdffd2554ce49c9b22f8c01303e0 P 8664b96aa0c04a3b9afe4298b1e475bb: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/f6cbcdffd2554ce49c9b22f8c01303e0/wal-000000023 (ops 111-115)
I20260812 06:16:45.060461  4930 log.cc:1079] T f6cbcdffd2554ce49c9b22f8c01303e0 P 8664b96aa0c04a3b9afe4298b1e475bb: Deleting log segment in path: /tmp/dist-test-taskETh2EY/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397202067-4403-0/minicluster-data/ts-0-root/wals/f6cbcdffd2554ce49c9b22f8c01303e0/wal-000000024 (ops 116-120)
I20260812 06:16:45.097949  4930 maintenance_manager.cc:643] P 8664b96aa0c04a3b9afe4298b1e475bb: LogGCOp(f6cbcdffd2554ce49c9b22f8c01303e0) complete. Timing: real 0.038s	user 0.000s	sys 0.038s Metrics: {}
I20260812 06:16:45.098445  5031 maintenance_manager.cc:419] P 8664b96aa0c04a3b9afe4298b1e475bb: Scheduling FlushDeltaMemStoresOp(f6cbcdffd2554ce49c9b22f8c01303e0): perf score=6.157687
I20260812 06:16:45.136257  4930 maintenance_manager.cc:643] P 8664b96aa0c04a3b9afe4298b1e475bb: FlushDeltaMemStoresOp(f6cbcdffd2554ce49c9b22f8c01303e0) complete. Timing: real 0.038s	user 0.022s	sys 0.001s Metrics: {"bytes_written":8205079,"delete_count":0,"lbm_write_time_us":10402,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:45.136720  5031 maintenance_manager.cc:419] P 8664b96aa0c04a3b9afe4298b1e475bb: Scheduling FlushDeltaMemStoresOp(f6cbcdffd2554ce49c9b22f8c01303e0): perf score=2.188937
I20260812 06:16:45.146947  4930 maintenance_manager.cc:643] P 8664b96aa0c04a3b9afe4298b1e475bb: FlushDeltaMemStoresOp(f6cbcdffd2554ce49c9b22f8c01303e0) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3662,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:45.147469  5031 maintenance_manager.cc:419] P 8664b96aa0c04a3b9afe4298b1e475bb: Scheduling UndoDeltaBlockGCOp(f6cbcdffd2554ce49c9b22f8c01303e0): 787 bytes on disk
I20260812 06:16:45.148065  4930 maintenance_manager.cc:643] P 8664b96aa0c04a3b9afe4298b1e475bb: UndoDeltaBlockGCOp(f6cbcdffd2554ce49c9b22f8c01303e0) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4}
I20260812 06:16:45.148846  5031 maintenance_manager.cc:419] P 8664b96aa0c04a3b9afe4298b1e475bb: Scheduling MajorDeltaCompactionOp(f6cbcdffd2554ce49c9b22f8c01303e0): perf score=1.000000
I20260812 06:16:47.344192  4930 maintenance_manager.cc:643] P 8664b96aa0c04a3b9afe4298b1e475bb: MajorDeltaCompactionOp(f6cbcdffd2554ce49c9b22f8c01303e0) complete. Timing: real 2.195s	user 0.960s	sys 1.233s Metrics: {"cfile_cache_miss":6159,"cfile_cache_miss_bytes":254431077,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":29,"delta_iterators_relevant":29,"dirs.queue_time_us":767,"lbm_read_time_us":92984,"lbm_reads_lt_1ms":6195,"lbm_write_time_us":717117,"lbm_writes_1-10_ms":8,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":6139,"peak_mem_usage":759003932,"reinsert_count":0,"spinlock_wait_cycles":26240,"thread_start_us":429,"threads_started":7,"update_count":30500}
I20260812 06:16:47.344911  5031 maintenance_manager.cc:419] P 8664b96aa0c04a3b9afe4298b1e475bb: Scheduling FlushDeltaMemStoresOp(f6cbcdffd2554ce49c9b22f8c01303e0): perf score=117.282687
I20260812 06:16:47.785679  4403 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.314s	user 1.637s	sys 0.141s
I20260812 06:16:47.833381  4403 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.047s	user 0.001s	sys 0.000s
I20260812 06:16:47.833935  4403 tablet_server.cc:179] TabletServer@127.4.76.193:0 shutting down...
I20260812 06:16:47.942265  4930 maintenance_manager.cc:643] P 8664b96aa0c04a3b9afe4298b1e475bb: FlushDeltaMemStoresOp(f6cbcdffd2554ce49c9b22f8c01303e0) complete. Timing: real 0.597s	user 0.256s	sys 0.192s Metrics: {"bytes_written":123072828,"delete_count":0,"lbm_write_time_us":255299,"lbm_writes_lt_1ms":3006,"reinsert_count":0,"update_count":15000}
I20260812 06:16:47.943138  4403 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:16:47.943444  4403 tablet_replica.cc:333] T f6cbcdffd2554ce49c9b22f8c01303e0 P 8664b96aa0c04a3b9afe4298b1e475bb: stopping tablet replica
I20260812 06:16:47.943602  4403 raft_consensus.cc:2243] T f6cbcdffd2554ce49c9b22f8c01303e0 P 8664b96aa0c04a3b9afe4298b1e475bb [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:47.943769  4403 raft_consensus.cc:2272] T f6cbcdffd2554ce49c9b22f8c01303e0 P 8664b96aa0c04a3b9afe4298b1e475bb [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:47.951421  4403 tablet_server.cc:196] TabletServer@127.4.76.193:0 shutdown complete.
I20260812 06:16:48.302855  4403 master.cc:562] Master@127.4.76.254:37433 shutting down...
I20260812 06:16:48.305857  4403 raft_consensus.cc:2243] T 00000000000000000000000000000000 P dc182d3f00b04ff8b8cb04e6551669c2 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:48.306059  4403 raft_consensus.cc:2272] T 00000000000000000000000000000000 P dc182d3f00b04ff8b8cb04e6551669c2 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:48.306131  4403 tablet_replica.cc:333] T 00000000000000000000000000000000 P dc182d3f00b04ff8b8cb04e6551669c2: stopping tablet replica
I20260812 06:16:48.318508  4403 master.cc:584] Master@127.4.76.254:37433 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (6210 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11195 ms total)

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