From 372119b17b837175d57cdf472bae89c4874dae2d Mon Sep 17 00:00:00 2001 From: Audric Ackermann Date: Tue, 25 May 2021 09:53:11 +1000 Subject: [PATCH] WIP --- ts/session/onions/onionSend.ts | 2 +- ts/session/snode_api/SNodeAPI.ts | 6 +- ts/session/snode_api/onions.ts | 94 ++++++++++-------- .../session/unit/onion/OnionErrors_test.ts | 96 +++++++++---------- 4 files changed, 108 insertions(+), 90 deletions(-) diff --git a/ts/session/onions/onionSend.ts b/ts/session/onions/onionSend.ts index f7c6e7399..446ed49cc 100644 --- a/ts/session/onions/onionSend.ts +++ b/ts/session/onions/onionSend.ts @@ -177,7 +177,7 @@ export const sendViaOnion = async ( }); }, { - retries: 10, // each path can fail 3 times before being dropped, we have 3 paths at most + retries: 9, // each path can fail 3 times before being dropped, we have 3 paths at most factor: 2, minTimeout: 200, maxTimeout: 4000, diff --git a/ts/session/snode_api/SNodeAPI.ts b/ts/session/snode_api/SNodeAPI.ts index 20ce08103..0ccda7a41 100644 --- a/ts/session/snode_api/SNodeAPI.ts +++ b/ts/session/snode_api/SNodeAPI.ts @@ -380,17 +380,17 @@ export async function storeOnNode(targetNode: Snode, params: SendParams): Promis export async function retrieveNextMessages( targetNode: Snode, lastHash: string, - pubkey: string + associatedWith: string ): Promise> { const params = { - pubKey: pubkey, + pubKey: associatedWith, lastHash: lastHash || '', }; // let exceptions bubble up try { // no retry for this one as this a call we do every few seconds while polling for messages - const result = await snodeRpc('retrieve', params, targetNode, pubkey); + const result = await snodeRpc('retrieve', params, targetNode, associatedWith); if (!result) { window?.log?.warn( diff --git a/ts/session/snode_api/onions.ts b/ts/session/snode_api/onions.ts index 5de319f1f..e5e811846 100644 --- a/ts/session/snode_api/onions.ts +++ b/ts/session/snode_api/onions.ts @@ -12,7 +12,7 @@ import { OnionPaths } from '../onions'; import { fromBase64ToArrayBuffer, toHex } from '../utils/String'; import pRetry from 'p-retry'; import { incrementBadPathCountOrDrop } from '../onions/onionPath'; - +import _ from 'lodash'; // hold the ed25519 key of a snode against the time it fails. Used to remove a snode only after a few failures (snodeFailureThreshold failures) const snodeFailureCount: Record = {}; @@ -205,7 +205,7 @@ async function process421Error( if (!lsrpcEd25519Key || !associatedWith) { throw new Error('status 421 without a final destination or no associatedWith makes no sense'); } - window?.log?.info('Invalidating swarm'); + window?.log?.info(`Invalidating swarm for ${associatedWith}`); await handle421InvalidSwarm(lsrpcEd25519Key, body, associatedWith); } } @@ -293,7 +293,9 @@ async function processAnyOtherErrorAtDestination( // response.status === 503 || // response.status === 504 || // response.status === 404 || - status !== 200 // this is pretty strong. a 400 (Oxen server error) will be handled as a bad path. + status !== 400 && + status !== 406 && // handled in process406Error + status !== 421 // handled in process421Error ) { window?.log?.warn(`[path] Got status at destination: ${status}`); @@ -360,14 +362,21 @@ export async function decodeOnionResult(symmetricKey: ArrayBuffer, ciphertext: s /** * Only exported for testing purpose */ -export async function processOnionResponse( - response: { text: () => Promise; status: number }, - symmetricKey: ArrayBuffer, - guardNode: Snode, - lsrpcEd25519Key?: string, - abortSignal?: AbortSignal, - associatedWith?: string -): Promise { +export async function processOnionResponse({ + response, + symmetricKey, + guardNode, + abortSignal, + associatedWith, + lsrpcEd25519Key, +}: { + response: { text: () => Promise; status: number }; + symmetricKey: ArrayBuffer; + guardNode: Snode; + lsrpcEd25519Key?: string; + abortSignal?: AbortSignal; + associatedWith?: string; +}): Promise { let ciphertext = ''; processAbortedRequest(abortSignal); @@ -437,16 +446,14 @@ export async function processOnionResponse( const status = jsonRes.status_code || jsonRes.status; await processOnionRequestErrorAtDestination({ statusCode: status, - body: plaintext, + body: jsonRes?.body, // this is really important. destinationEd25519: lsrpcEd25519Key, associatedWith, }); return jsonRes as SnodeResponse; } catch (e) { - window?.log?.error( - `[path] lokiRpc::processingOnionResponse - parse error outer json ${e.code} ${e.message} json: '${plaintext}'` - ); + window?.log?.error(`[path] lokiRpc::processingOnionResponse - Rethrowing error ${e.message}'`); throw e; } } @@ -490,27 +497,36 @@ async function handle421InvalidSwarm(snodeEd25519: string, body: string, associa window?.log?.warn('Got a 421 without an associatedWith publickey'); return; } + const exceptionMessage = '421 handled. Retry this request with a new targetNode'; try { const json = JSON.parse(body); // The snode isn't associated with the given public key anymore if (json.snodes?.length) { // the snode gave us the new swarm. Save it for the next retry - window?.log?.warn('Wrong swarm, now looking at snodes', json.snodes); + window?.log?.warn( + 'Wrong swarm, now looking at snodes', + json.snodes.map((s: any) => s.pubkey_ed25519) + ); - return updateSwarmFor(associatedWith, json.snodes); + await updateSwarmFor(associatedWith, json.snodes); + throw new pRetry.AbortError(exceptionMessage); } // remove this node from the swarm of this pubkey - return dropSnodeFromSwarmIfNeeded(associatedWith, snodeEd25519); + await dropSnodeFromSwarmIfNeeded(associatedWith, snodeEd25519); } catch (e) { - console.warn('dropSnodeFromSwarmIfNeeded', snodeEd25519); - window?.log?.warn( - 'Got error while parsing 421 result. Dropping this snode from the swarm of this pubkey', - e - ); - // could not parse result. Consider that this snode as invalid - return dropSnodeFromSwarmIfNeeded(associatedWith, snodeEd25519); + if (e.message !== exceptionMessage) { + console.warn('dropSnodeFromSwarmIfNeeded', snodeEd25519); + window?.log?.warn( + 'Got error while parsing 421 result. Dropping this snode from the swarm of this pubkey', + e + ); + // could not parse result. Consider that this snode as invalid + await dropSnodeFromSwarmIfNeeded(associatedWith, snodeEd25519); + } } + // this is important we throw so another retry is made and we exit the handling of that reponse + throw new pRetry.AbortError(exceptionMessage); } /** @@ -604,24 +620,23 @@ const sendOnionRequestHandlingSnodeEject = async ({ finalRelayOptions, abortSignal, }); - // this call will handle the common onion failure logic. // if an error is not retryable a AbortError is triggered, which is handled by pRetry and retries are stopped - const processed = await processOnionResponse( + const processed = await processOnionResponse({ response, - decodingSymmetricKey, - nodePath[0], - finalDestOptions?.destination_ed25519_hex, + symmetricKey: decodingSymmetricKey, + guardNode: nodePath[0], + lsrpcEd25519Key: finalDestOptions?.destination_ed25519_hex, abortSignal, - associatedWith - ); + associatedWith, + }); return processed; }; /** * - * Onion request looks like this + * Onion requests looks like this * Sender -> 1 -> 2 -> 3 -> Receiver * 1, 2, 3 = onion Snodes * @@ -649,6 +664,9 @@ const sendOnionRequest = async ({ }) => { // get destination pubkey in array buffer format let destX25519hex = destX25519Any; + + // Warning be sure to do a copy otherwise the delete below creates issue with retries + const copyFinalDestOptions = _.cloneDeep(finalDestOptions); if (typeof destX25519hex !== 'string') { // convert AB to hex window?.log?.warn('destX25519hex was not a string'); @@ -658,14 +676,14 @@ const sendOnionRequest = async ({ // safely build destination let targetEd25519hex; - if (finalDestOptions.destination_ed25519_hex) { + if (copyFinalDestOptions.destination_ed25519_hex) { // snode destination - targetEd25519hex = finalDestOptions.destination_ed25519_hex; + targetEd25519hex = copyFinalDestOptions.destination_ed25519_hex; // eslint-disable-next-line no-param-reassign - delete finalDestOptions.destination_ed25519_hex; + delete copyFinalDestOptions.destination_ed25519_hex; } - const options = finalDestOptions; // lint + const options = copyFinalDestOptions; // lint // do we need this? options.headers = options.headers || {}; @@ -791,7 +809,7 @@ export async function lokiOnionFetch( return onionFetchRetryable(targetNode, body, associatedWith); }, { - retries: 10, + retries: 9, factor: 1, minTimeout: 200, maxTimeout: 2000, diff --git a/ts/test/session/unit/onion/OnionErrors_test.ts b/ts/test/session/unit/onion/OnionErrors_test.ts index d773bb8b3..409c2b2e3 100644 --- a/ts/test/session/unit/onion/OnionErrors_test.ts +++ b/ts/test/session/unit/onion/OnionErrors_test.ts @@ -102,13 +102,12 @@ describe('OnionPathsErrors', () => { const abortController = new AbortController(); abortController.abort(); try { - await processOnionResponse( - getFakeResponse(), - new Uint8Array(), - guardSnode1, - undefined, - abortController.signal - ); + await processOnionResponse({ + response: getFakeResponse(), + symmetricKey: new Uint8Array(), + guardNode: guardSnode1, + abortSignal: abortController.signal, + }); throw new Error('Error expected'); } catch (e) { expect(e.message).to.equal('Request got aborted'); @@ -119,7 +118,11 @@ describe('OnionPathsErrors', () => { it('throws an non retryable error we get a 406 status code', async () => { try { - await processOnionResponse(getFakeResponse(406), new Uint8Array(), guardSnode1, undefined); + await processOnionResponse({ + response: getFakeResponse(406), + symmetricKey: new Uint8Array(), + guardNode: guardSnode1, + }); throw new Error('Error expected'); } catch (e) { expect(e.message).to.equal('You clock is out of sync with the network. Check your clock.'); @@ -135,14 +138,14 @@ describe('OnionPathsErrors', () => { const targetNode = otherNodesPubkeys[0]; try { - await processOnionResponse( - getFakeResponse(421), - new Uint8Array(), - guardSnode1, - targetNode, - undefined, - associatedWith - ); + await processOnionResponse({ + response: getFakeResponse(421), + symmetricKey: new Uint8Array(), + guardNode: guardSnode1, + lsrpcEd25519Key: targetNode, + + associatedWith, + }); throw new Error('Error expected'); } catch (e) { expect(e.message).to.equal('Bad Path handled. Retry this request. Status: 421'); @@ -165,14 +168,13 @@ describe('OnionPathsErrors', () => { otherNodesArray[6], ]; try { - await processOnionResponse( - getFakeResponse(421, JSON.stringify({ snodes: resultExpected })), - new Uint8Array(), - guardSnode1, - targetNode, - undefined, - associatedWith - ); + await processOnionResponse({ + response: getFakeResponse(421, JSON.stringify({ snodes: resultExpected })), + symmetricKey: new Uint8Array(), + guardNode: guardSnode1, + lsrpcEd25519Key: targetNode, + associatedWith, + }); throw new Error('Error expected'); } catch (e) { expect(e.message).to.equal('Bad Path handled. Retry this request. Status: 421'); @@ -188,14 +190,14 @@ describe('OnionPathsErrors', () => { const targetNode = otherNodesPubkeys[0]; try { - await processOnionResponse( - getFakeResponse(421, 'THIS IS SOME INVALID JSON'), - new Uint8Array(), - guardSnode1, - targetNode, - undefined, - associatedWith - ); + await processOnionResponse({ + response: getFakeResponse(421, 'THIS IS SOME INVALID JSON'), + symmetricKey: new Uint8Array(), + guardNode: guardSnode1, + lsrpcEd25519Key: targetNode, + + associatedWith, + }); throw new Error('Error expected'); } catch (e) { expect(e.message).to.equal('Bad Path handled. Retry this request. Status: 421'); @@ -223,14 +225,13 @@ describe('OnionPathsErrors', () => { .resolves({ plaintext: json, ciphertextBuffer: new Uint8Array() }); try { - await processOnionResponse( - getFakeResponse(200, fromArrayBufferToBase64(Buffer.from(json))), - new Uint8Array(), - guardSnode1, - targetNode, - undefined, - associatedWith - ); + await processOnionResponse({ + response: getFakeResponse(200, fromArrayBufferToBase64(Buffer.from(json))), + symmetricKey: new Uint8Array(), + guardNode: guardSnode1, + lsrpcEd25519Key: targetNode, + associatedWith, + }); throw new Error('Error expected'); } catch (e) { expect(e.message).to.equal('Bad Path handled. Retry this request. Status: 421'); @@ -263,14 +264,13 @@ describe('OnionPathsErrors', () => { .resolves({ plaintext: json, ciphertextBuffer: new Uint8Array() }); try { - await processOnionResponse( - getFakeResponse(200, json), - new Uint8Array(), - guardSnode1, - targetNode, - undefined, - associatedWith - ); + await processOnionResponse({ + response: getFakeResponse(200, json), + symmetricKey: new Uint8Array(), + guardNode: guardSnode1, + lsrpcEd25519Key: targetNode, + associatedWith, + }); throw new Error('Error expected'); } catch (e) { expect(e.message).to.equal('Bad Path handled. Retry this request. Status: 421');