GET request fails to find locally cached contract after different client's PUT

[sanity]

Problem Summary

When Client 1 (Alice) PUTs a contract and then Client 2 (Bob) tries to GET the same contract from the same node, the GET times out instead of finding the contract in local storage.

How to Reproduce

Prerequisites

• A Freenet node running and connected to the network (e.g., technic connected to gateway)
• riverctl CLI installed

Steps

# Set up test directories
ALICE_DIR=/tmp/alice-cli-test
BOB_DIR=/tmp/bob-cli-test
mkdir -p $ALICE_DIR $BOB_DIR

# Step 1: Alice creates a room (this does a PUT)
riverctl --config-dir $ALICE_DIR room create --name 'test-room' --nickname 'alice' -f json
# Note the owner_key from output

# Step 2: Alice creates an invite
riverctl --config-dir $ALICE_DIR invite create <OWNER_KEY> -f json
# Note the invitation_code from output

# Step 3: Bob accepts invite (this does a GET - THIS TIMES OUT)
riverctl --config-dir $BOB_DIR invite accept "<INVITATION_CODE>" --nickname bob -f json
# Error: Timeout waiting for GET response after 10 seconds

Alternative reproduction (direct WebSocket API)

The test file crates/core/tests/multi_client_get_regression.rs contains two tests:

• test_different_client_get_after_put - Client 1 PUTs, disconnects, Client 2 GETs
• test_concurrent_clients_put_then_get - Both clients connected, Client 1 PUTs, Client 2 GETs immediately

Note: These tests pass in the test network but the bug reproduces on live technic node.

Live Evidence (from technic logs)

02:44:06.301 - PUT operation logs "caching locally" for contract vHpRZZFdgwPKpU82wRw8FMS3iESxbZyVuEWirRL2Awu
02:44:06.529 - GET operation logs "Contract not found" for the SAME contract (228ms later)

The contract was stored during PUT but GET's local cache check returns None.

Code Path Analysis

PUT path (crates/core/src/operations/put.rs):

• request_put() at lines 1358-1374 calls put_contract() to store locally BEFORE forwarding
• Line 1597 logs "No peers available for forwarding - caching locally" (gateway in skip_list)

GET path (crates/core/src/client_events/mod.rs):

• Lines 853-878: GET first checks local storage via notify_contract_handler(GetQuery)
• Lines 880-932: Returns immediately if found locally
• Lines 934+: Routes to network if NOT found locally

What We've Ruled Out

• ContractKey mismatch: Instance IDs are identical between PUT and GET
• Test framework issues: Local tests pass (GET completes in ~2ms from local cache)
• Timing: 228ms between PUT completion and GET is plenty of time

Remaining Hypotheses

1. Storage layer issue: put_contract() succeeds but data isn't persisted correctly to redb
2. Different storage paths: PUT and GET use different contract handlers or storage backends
3. Client isolation: Some per-client caching that doesn't share between clients
4. Race condition: Something specific to the live environment vs test network

Next Steps

• Run with RUST_LOG=debug to trace exact storage flow through put_contract() and notify_contract_handler(GetQuery)
• Verify redb database actually contains the contract after PUT
• Compare storage lookup code paths between PUT's storage and GET's retrieval

Environment

• Technic node at 136.62.52.28:43227 behind NAT
• Gateway at 5.9.111.215:31337
• Freenet version 0.1.42

Related Files

• crates/core/tests/multi_client_get_regression.rs - Regression tests
• crates/core/src/operations/put.rs - PUT operation
• crates/core/src/operations/get.rs - GET operation
• crates/core/src/client_events/mod.rs - Client request routing

[AI-assisted - Claude]

[github-actions]

🤖 Auto-labeled

Applied labels:

• T-bug (98% confidence)
• P-high (88% confidence)
• A-contracts (92% confidence)
• A-networking (80% confidence)

Reasoning: The report describes a reproducible failure where a contract PUT by one client is not found by a subsequent GET from another client on the same node — this is a functional bug. It affects client operations and live nodes (not just tests), so it should be treated with high priority. The root cause likely involves contract storage/lookup or client-local caching, so A-contracts is relevant; because GET/PUT and forwarding behavior are involved, A-networking is also applicable. Fix will likely require moderate investigation into storage (redb) and client routing code paths, so effort is estimated medium.

Previous labels: none

If these labels are incorrect, please update them. This helps improve the auto-labeling system.

[sanity]

Code Analysis Update

After deeper code analysis, I found the error path:

Error Origin

The error "contract X not found in store" comes from wasm_runtime/runtime.rs:241:

let contract = self.contract_store.fetch_contract(key, parameters)
    .ok_or_else(|| RuntimeInnerError::ContractNotFound(*key))?;

This is called during prepare_contract_call which is invoked by validate_state.

Flow in upsert_contract_state (executor/runtime.rs)

1. Lines 115-135: Check if contract exists via fetch_contract, store if needed via store_contract
2. Line 160: Call validate_state which internally calls prepare_contract_call
3. prepare_contract_call calls fetch_contract again

The contract SHOULD be stored at step 1 before validate_state is called at step 2. But the error indicates fetch_contract returns None during validate_state.

store_contract stores to:

• contract_cache (hashmap keyed by code_hash)
• Disk (wasm file)
• Index (key_to_code_part)

fetch_contract looks up:

• First checks contract_cache.get(code_hash)
• Falls back to key_to_code_part.get(key.id())

Hypothesis: Cache Synchronization

The contract_cache is a stretto cache. If store_contract inserts into the cache but the cache hasn't synced yet, fetch_contract might return None.

Looking at line 139-140 of contract_store.rs:

self.contract_cache.insert(*code_hash, Arc::new(ContractCode::from(data)), size);

Stretto caches have eventual consistency - inserts may not be immediately visible. This could explain why:

• Store succeeds
• Immediate fetch fails

Next Steps

1. Test if adding a sync/wait after store_contract fixes the issue
2. Or modify fetch_contract to check the disk fallback first when cache misses after recent store

[AI-assisted - Claude]

[sanity]

Root Cause Confirmed: Stretto Cache Eventual Consistency

The Bug

The stretto::Cache used for contract_cache in ContractStore is eventually consistent. When store_contract calls insert(), the value may not be immediately visible to subsequent get() calls because stretto buffers writes to background threads.

From stretto documentation:

stretto starts two extra threads - one policy thread and one writing thread. Inserts are buffered and processed asynchronously.

Where It Happens

In contract_store.rs:

// Line 139-140 in store_contract()
self.contract_cache.insert(*code_hash, Arc::new(ContractCode::from(data)), size);
// Returns without calling wait()!

Then in executor/runtime.rs upsert_contract_state:

1. Line 124-127: Calls store_contract() which inserts to cache
2. Line 160: Immediately calls validate_state()
3. validate_state → prepare_contract_call → fetch_contract which calls get() on the cache
4. Cache get() returns None because insert hasn't been flushed yet!

Fix

Call contract_cache.wait() after insert in store_contract():

// In store_contract(), after inserting to cache:
self.contract_cache.insert(*code_hash, Arc::new(ContractCode::from(data)), size);
self.contract_cache.wait();  // <-- ADD THIS

Or alternatively, the fix could be applied in fetch_contract to check the disk fallback first when the cache misses, since the disk write happens synchronously.

Why Tests Pass But Production Fails

In tests with freenet-test-network, there may be enough time between PUT requests for the cache to flush, or the test environment's simpler network topology doesn't trigger the immediate local validation path.

In production, when a PUT arrives and the contract needs to be validated immediately, there's no delay between store and fetch, exposing the race condition.

[AI-assisted - Claude]