Skip to content

Commit 7405a29

Browse files
frooozefroooze
committed
fix: stop misclassifying partial fills as full when rawOnChain cache is stale
The XRP-BTS bot went stale on 2026-07-03 around 00:34:51 because order 1.7.572840453 (slot-109) was a 2.5788 XRP sell that received 5 partial fills totaling exactly 2.5788 XRP. The bot only saw 4 of the 5 fills, marked the order as fully filled on the FIRST fill, and dropped the remaining 4 at debug level — leaving a 0.0030 XRP residual on chain with no in-memory record. Root cause was in syncFromFillHistory (modules/order/sync_engine.ts): `isEffectivelyFull = (newSizeInt <= 0)` trusted the cached rawOnChain.for_sale unconditionally. When the cache had a stale (smaller) value from a prior in-memory reduction, the subtraction crossed zero on a partial fill and the order was misclassified as full. Subsequent fills then hit the "order not found in active grid" branch and were silently dropped. ## What changed - `modules/chain_orders.ts`: new `readSingleOrder(orderId, timeoutMs)` helper that wraps `get_objects([id])`. Returns `null` only on a real "order is gone" (authoritative empty signal); throws on connection/RPC failure so the caller can distinguish "tried-and-gone" from "tried-and-failed". - `modules/order/sync_engine.ts`: `syncFromFillHistory` now refetches via `readSingleOrder` only when the cached `for_sale` is *smaller* than the grid's own size (a "drift signal" — chain can only decrease). No TTL, no time-based refetch. The cache is the source of truth; the chain is only consulted when the cache and the grid demonstrably disagree. `isEffectivelyFull` now requires either a chain-confirmed empty (drift refetch returned null), the grid also being at 0, or the other side rounding to 0. The legacy `newSizeInt <= 0` fast-path is gone. - Three `rawOnChain` population sites in `_doSyncFromOpenOrders` now stamp `fetchedAt: Date.now()` so the partial-fill branch can use the refetched value as a fresh baseline. - `tests/test_ghost_order_fix.ts`: seeds a fresh `rawOnChain` so the test no longer depends on a live chain connection. - `tests/test_sync_fill_drift_refetch.ts` (new): 5 sub-cases for the new behaviour — drift + working refetch, drift + null refetch, drift + refetch error, no drift (self-correcting), no cache (legacy fallback). ## Why drift-only, not TTL A stale-but-consistent cache is still correct; a fresh-but-wrong cache is the actual bug we're guarding against, and the drift signal catches that. A time-based TTL would refetch on every open-orders sync window even when the cache is correct. Open-orders sync remains the ultimate recovery channel for missed events. ## Testing notes - `npm run typecheck` clean - `tests/test_sync_fill_drift_refetch.ts` (new) ✓ - `tests/test_ghost_order_fix.ts` ✓ - `tests/test_precision_integration.ts` ✓ - `tests/test_multifill_opposite_partial.ts` ✓ - `tests/test_main_loop_sync_fill_rebalance.ts` ✓ - `tests/test_cow_structural_resync.ts` ✓ - `tests/test_cow_concurrent_fills.ts` ✓ - `tests/test_fill_batch_chunking.ts` ✓ - `tests/test_boundary_sync_logic.ts` ✓ - Pre-existing failures (unrelated): `tests/test_fill_replay_guards.ts`, `claw/tests/test_dexbot_profiles.ts` — confirmed by stashing the diff and running them on the unmodified `test` branch.
1 parent 5ab8cce commit 7405a29

4 files changed

Lines changed: 450 additions & 27 deletions

File tree

‎modules/chain_orders.ts‎

Lines changed: 40 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -468,9 +468,47 @@ async function executeViaDaemonToken(accountName, signingToken, operations) {
468468
return getKeyStore().executeOperations(accountName, operations, signingToken);
469469
}
470470

471+
/**
472+
* Fetch a single limit order by id from the blockchain.
473+
*
474+
* Used by the sync engine as a targeted refetch when the cached `rawOnChain.for_sale`
475+
* is observed to be smaller than the grid's own size (a "drift signal" — the chain
476+
* value can only decrease, never grow on its own). The refetch is the only
477+
* operation that re-anchors the cache to chain truth for an order whose in-memory
478+
* baseline has fallen out of sync (e.g., a missed fill event).
479+
*
480+
* Return semantics:
481+
* - returns the raw order object on success
482+
* - returns `null` if the order is genuinely absent from the chain (`get_objects`
483+
* returns null for missing ids) — this is the authoritative "order is gone"
484+
* signal
485+
* - THROWS on any other error (connection timeout, RPC failure, etc.). Callers
486+
* use try/catch to distinguish "tried-and-gone" (null) from "tried-and-failed"
487+
* (caught) and fall back to the cache.
488+
*
489+
* @param {string} orderId - BitShares limit order id (e.g. "1.7.572840453")
490+
* @param {number} [timeoutMs] - Connection timeout in milliseconds. Defaults to
491+
* the full CONNECTION_TIMEOUT_MS (30s); sync-engine callers should pass a
492+
* smaller value so a disconnected node does not stall a fill cycle.
493+
* @returns {Promise<Object|null>} Raw chain order object, or null if not found
494+
* @throws {Error} On connection or RPC failure
495+
*/
496+
async function readSingleOrder(orderId, timeoutMs = TIMING.CONNECTION_TIMEOUT_MS) {
497+
if (!orderId || typeof orderId !== 'string') return null;
498+
await waitForConnected(timeoutMs);
499+
if (!BitShares || !BitShares.db || typeof BitShares.db.get_objects !== 'function') {
500+
throw new Error('readSingleOrder: BitShares.db.get_objects unavailable');
501+
}
502+
const results = await BitShares.db.get_objects([orderId]);
503+
const order = Array.isArray(results) ? results[0] : null;
504+
if (!order) return null;
505+
if (order.id !== orderId) return null;
506+
return order;
507+
}
508+
471509
/**
472510
* Fetch all open limit orders for an account from the blockchain.
473-
* Uses AsyncLock to safely access preferredAccountId (fixes Issue #2).
511+
* Uses AsyncLock to safely access preferred accountId (fixes Issue #2).
474512
* @param {string|null} accountId - Account ID to query (uses preferred if null)
475513
* @param {number} timeoutMs - Connection timeout in milliseconds
476514
* @param {boolean} suppress_log - Whether to suppress the log
@@ -1210,6 +1248,7 @@ export = {
12101248
resolveAccountId,
12111249
resolveAccountName,
12121250
readOpenOrders,
1251+
readSingleOrder,
12131252
listenForFills,
12141253
updateOrder,
12151254
createOrder,

‎modules/order/sync_engine.ts‎

Lines changed: 118 additions & 17 deletions
Original file line numberDiff line numberDiff line change
@@ -612,8 +612,16 @@ class SyncEngine {
612612
const chainOrder = parsedChainOrders.get(gridOrder.orderId);
613613
let updatedOrder = { ...gridOrder };
614614
chainOrderIdsOnGrid.add(gridOrder.orderId);
615-
// Store raw blockchain data in grid slot for later update calculation
616-
updatedOrder.rawOnChain = rawChainOrders.get(gridOrder.orderId);
615+
// Store raw blockchain data in grid slot for later update calculation.
616+
// Tag the snapshot with `fetchedAt` so the drift check in
617+
// syncFromFillHistory can distinguish a fresh chain read from a
618+
// never-synced entry (the latter has no fetchedAt and is treated
619+
// as if grid-equals-chain, since the cache is just a thin mirror
620+
// of the grid baseline at this point).
621+
const rawSnapshot = rawChainOrders.get(gridOrder.orderId);
622+
updatedOrder.rawOnChain = rawSnapshot
623+
? { ...rawSnapshot, fetchedAt: Date.now() }
624+
: rawSnapshot;
617625

618626
// Side mismatch: keep slot untouched and queue cancellation for stale chain order.
619627
if (gridOrder.type !== chainOrder.type) {
@@ -719,7 +727,10 @@ class SyncEngine {
719727
const wasPartial = match.state === ORDER_STATES.PARTIAL;
720728
bestMatch.orderId = chainOrderId;
721729
bestMatch.state = wasVirtual ? ORDER_STATES.ACTIVE : match.state;
722-
bestMatch.rawOnChain = rawChainOrders.get(chainOrderId);
730+
const bestMatchRaw = rawChainOrders.get(chainOrderId);
731+
bestMatch.rawOnChain = bestMatchRaw
732+
? { ...bestMatchRaw, fetchedAt: Date.now() }
733+
: bestMatchRaw;
723734
matchedGridOrderIds.add(bestMatch.id);
724735

725736
// Reconstruct btsFeeState from raw chain order's deferred_fee.
@@ -849,7 +860,9 @@ class SyncEngine {
849860
state: adoptedState,
850861
size: chainOrder.size,
851862
price: chainOrder.price,
852-
rawOnChain: adoptedRaw,
863+
rawOnChain: adoptedRaw
864+
? { ...adoptedRaw, fetchedAt: Date.now() }
865+
: adoptedRaw,
853866
...(adoptedBtsFeeState ? { btsFeeState: adoptedBtsFeeState } : {}),
854867
};
855868
matchedGridOrderIds.add(adoptedSlot.id);
@@ -995,32 +1008,113 @@ class SyncEngine {
9951008

9961009
const currentSizeIntFromGrid = floatToBlockchainInt(currentSize, precision);
9971010
const rawForSaleInt = toFiniteNumber(matchedGridOrder?.rawOnChain?.for_sale, null);
998-
const currentSizeInt = Number.isFinite(rawForSaleInt)
999-
? Math.max(0, Math.round(rawForSaleInt))
1011+
let effectiveRawForSale = rawForSaleInt;
1012+
let chainConfirmsEmpty = false;
1013+
let chainRefetched = false;
1014+
1015+
// -----------------------------------------------------------------
1016+
// Drift-only refetch: the cache is self-correcting across sequential
1017+
// websocket fills, but if a fill was ever missed (reconnect, restart,
1018+
// reorg, external activity), the cache and the grid can disagree.
1019+
// The only signal we can detect from the in-memory state is a
1020+
// consistent drift: cached for_sale < grid size. Chain `for_sale`
1021+
// can only decrease, so a smaller cached value is an obvious
1022+
// inconsistency that warrants a targeted refetch.
1023+
//
1024+
// We do NOT refetch on a time-based TTL. A stale-but-consistent
1025+
// cache is still correct; a fresh-but-wrong cache is the actual
1026+
// bug we're guarding against, and the drift signal catches that.
1027+
// The refetch is best-effort: a network error falls back to the
1028+
// cache with a warning, and the open-orders sync is the ultimate
1029+
// recovery channel.
1030+
// -----------------------------------------------------------------
1031+
const driftSignal = Number.isFinite(rawForSaleInt)
1032+
&& Math.round(rawForSaleInt) < currentSizeIntFromGrid;
1033+
1034+
if (driftSignal) {
1035+
try {
1036+
const { readSingleOrder } = require('../chain_orders');
1037+
const fresh = await readSingleOrder(orderId, 3000);
1038+
if (fresh) {
1039+
const freshForSale = toFiniteNumber(fresh.for_sale, null);
1040+
if (Number.isFinite(freshForSale)) {
1041+
effectiveRawForSale = freshForSale;
1042+
chainRefetched = true;
1043+
mgr.logger.log(
1044+
`[SYNC] Drift detected for ${orderId} (cached=${rawForSaleInt} < grid=${currentSizeIntFromGrid}); ` +
1045+
`refetched for_sale=${freshForSale}`,
1046+
'warn'
1047+
);
1048+
}
1049+
} else {
1050+
// Chain returned null — the order is genuinely absent.
1051+
// This is the authoritative "chain confirms empty"
1052+
// signal (vs. an RPC failure which would have thrown).
1053+
chainConfirmsEmpty = true;
1054+
mgr.logger.log(
1055+
`[SYNC] Drift refetch for ${orderId} returned null; chain confirms empty`,
1056+
'info'
1057+
);
1058+
}
1059+
} catch (refetchErr: any) {
1060+
mgr.logger.log(
1061+
`[SYNC] Drift refetch for ${orderId} failed; falling back to cache: ` +
1062+
`${refetchErr?.message || refetchErr}`,
1063+
'warn'
1064+
);
1065+
}
1066+
}
1067+
1068+
// Chain-confirmed-empty gate: only true when the drift refetch
1069+
// returned null (i.e., the chain is definitively saying the order
1070+
// is gone). We deliberately do not trust a cached 0 from a
1071+
// never-refetched source — that would misclassify a 0.003 XRP
1072+
// residual as a full fill.
1073+
if (chainRefetched
1074+
&& Number.isFinite(effectiveRawForSale)
1075+
&& Math.round(effectiveRawForSale) <= 0) {
1076+
chainConfirmsEmpty = true;
1077+
}
1078+
1079+
const currentSizeInt = Number.isFinite(effectiveRawForSale)
1080+
? Math.max(0, Math.round(effectiveRawForSale))
10001081
: currentSizeIntFromGrid;
10011082
const filledAmountInt = floatToBlockchainInt(filledAmount, precision);
10021083
const newSizeInt = Math.max(0, currentSizeInt - filledAmountInt);
10031084
const newSize = blockchainToFloat(newSizeInt, precision, true); // needed for partial fills
10041085

1005-
if (Number.isFinite(rawForSaleInt) && currentSizeInt !== currentSizeIntFromGrid) {
1086+
if (Number.isFinite(effectiveRawForSale) && currentSizeInt !== currentSizeIntFromGrid) {
10061087
mgr.logger.log(
1007-
`[SYNC] Using rawOnChain.for_sale baseline for ${orderId}: raw=${currentSizeInt}, grid=${currentSizeIntFromGrid}`,
1088+
`[SYNC] Using rawOnChain.for_sale baseline for ${orderId}: raw=${currentSizeInt}, grid=${currentSizeIntFromGrid}` +
1089+
(chainRefetched ? ' (refetched)' : ''),
10081090
'debug'
10091091
);
10101092
}
10111093

1012-
// CRITICAL (v0.5.1 Robustness): We must detect if an order is "effectively" full.
1013-
// An order is full if its size asset reaches 0 OR if the OTHER side reaches 0.
1014-
// If it's closed on chain but we see a tiny remainder here, it's a Ghost Order.
1015-
let isEffectivelyFull = (newSizeInt <= 0);
1094+
// CRITICAL (v0.5.1 Robustness + chain-confirmed-empty gate):
1095+
// An order is "effectively" full if EITHER:
1096+
// 1. The chain has confirmed the order is gone (the drift
1097+
// refetch above returned null), OR
1098+
// 2. The grid itself is at 0 (no drift between grid and chain), OR
1099+
// 3. The OTHER side rounds to 0 (the chain will close the order
1100+
// regardless of the residual on the size side — see
1101+
// test_ghost_order_fix.ts for the intended behaviour).
1102+
//
1103+
// We deliberately do NOT use `newSizeInt <= 0` as a fast-path
1104+
// full-fill signal: with a stale cached rawOnChain, that arithmetic
1105+
// can be wrong and misclassify a partial fill as full. The
1106+
// 30-satoshi residual that triggered the bot-stale incident is the
1107+
// motivating case.
1108+
const gridAlsoEmpty = currentSizeIntFromGrid <= 0;
1109+
let isEffectivelyFull = chainConfirmsEmpty || gridAlsoEmpty;
10161110

10171111
if (!isEffectivelyFull) {
1018-
// Check the "other" side's precision. If the remaining amount to receive/pay
1112+
// Check the "other" side's precision. If the remaining amount to receive/pay
10191113
// rounds to 0 on the blockchain, the order will be closed regardless of newSizeInt.
10201114
const otherPrecision = (orderType === ORDER_TYPES.SELL) ? assetBPrecision : assetAPrecision;
10211115
const price = matchedGridOrder.price;
10221116
const otherSize = (orderType === ORDER_TYPES.SELL) ? newSize * price : newSize / price;
1023-
1117+
10241118
if (floatToBlockchainInt(otherSize, otherPrecision) <= 0) {
10251119
mgr.logger.log(`[SYNC] Order ${orderId} (slot ${matchedGridOrder.id}) other-side (${otherSize}) rounds to 0. Treating as full fill to trigger rotation.`, 'info');
10261120
isEffectivelyFull = true;
@@ -1058,12 +1152,19 @@ class SyncEngine {
10581152
const { btsFeeState, ...matchedWithoutDeferredFee } = matchedGridOrder;
10591153
let updatedOrder = { ...matchedWithoutDeferredFee, state: ORDER_STATES.PARTIAL };
10601154

1061-
// Update cached raw order integer instead of deleting it
1155+
// Update cached raw order integer instead of deleting it.
1156+
// If the drift refetch above pulled a fresh chain value, use
1157+
// it as the new baseline (subtracting this fill) and stamp
1158+
// fetchedAt so the cache is consistent for the next fill.
10621159
if (updatedOrder.rawOnChain && updatedOrder.rawOnChain.for_sale !== undefined) {
1063-
const currentForSale = toFiniteNumber(updatedOrder.rawOnChain.for_sale);
1160+
const baselineForSale = (chainRefetched && Number.isFinite(effectiveRawForSale))
1161+
? effectiveRawForSale
1162+
: toFiniteNumber(updatedOrder.rawOnChain.for_sale);
1163+
const nextForSaleInt = Math.max(0, Math.round(baselineForSale) - filledAmountInt);
10641164
updatedOrder.rawOnChain = {
10651165
...updatedOrder.rawOnChain,
1066-
for_sale: String(Math.max(0, currentForSale - filledAmountInt))
1166+
for_sale: String(nextForSaleInt),
1167+
fetchedAt: Date.now()
10671168
};
10681169
}
10691170

‎tests/test_ghost_order_fix.ts‎

Lines changed: 14 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -36,21 +36,26 @@ async function runTests() {
3636
console.log(' - Testing tiny remainder rounding to full fill (SyncEngine)...');
3737
{
3838
const manager = await createManager();
39-
39+
4040
// Setup initial order: Buy XRP with 249.27798 BTS (exactly the case from the log)
4141
const initialSize = 249.27798;
42+
// Provide a fresh rawOnChain snapshot. With drift-only refetch (no TTL),
43+
// the sync engine will only consult the chain if the cache and the grid
44+
// disagree. Seeding the cache here keeps the test self-contained.
45+
const initialSizeInt = Math.round(initialSize * 100000);
4246
await manager._updateOrder({
43-
id: 'slot-164',
44-
state: ORDER_STATES.ACTIVE,
47+
id: 'slot-164',
48+
state: ORDER_STATES.ACTIVE,
4549
type: ORDER_TYPES.BUY,
46-
size: initialSize,
47-
price: 1450.94267,
48-
orderId: '1.7.570062650'
50+
size: initialSize,
51+
price: 1450.94267,
52+
orderId: '1.7.570062650',
53+
rawOnChain: { for_sale: String(initialSizeInt), fetchedAt: Date.now() }
4954
});
5055

5156
// Simulate a fill that leaves 0.00003 BTS (below minAbsoluteSize of 0.0005)
5257
const filledAmount = 249.27795; // Resulting in 0.00003 remainder
53-
58+
5459
const fillEvent = {
5560
block_num: 123456,
5661
id: '1.11.999',
@@ -63,11 +68,11 @@ async function runTests() {
6368
};
6469

6570
const result = await manager.sync.syncFromFillHistory(fillEvent);
66-
71+
6772
// Assertions
6873
assert.strictEqual(result.partialFill, false, 'Should be treated as full fill despite non-zero remainder');
6974
assert.strictEqual(result.filledOrders[0].isPartial, undefined, 'filledOrder should NOT be marked as partial to trigger rotation');
70-
75+
7176
const slot = manager.orders.get('slot-164');
7277
assert.strictEqual(slot.state, ORDER_STATES.VIRTUAL, 'Order should be virtualized after full fill');
7378
assert.strictEqual(slot.size, 0, 'Virtual order size should be 0');

0 commit comments

Comments
 (0)