From ed53ab43e64e3a8764d8d2abd1235f0dd609a2ac Mon Sep 17 00:00:00 2001 From: Audric Ackermann Date: Tue, 18 May 2021 13:51:01 +1000 Subject: [PATCH] WIP --- ts/components/session/ActionsPanel.tsx | 2 +- ts/session/onions/onionPath.ts | 48 ++-- ts/session/onions/onionSend.ts | 169 ++++++-------- ts/session/sending/LokiMessageApi.ts | 4 +- ts/session/snode_api/SNodeAPI.ts | 23 +- ts/session/snode_api/onions.ts | 301 +++++++++++++++---------- ts/session/snode_api/snodePool.ts | 16 +- 7 files changed, 302 insertions(+), 261 deletions(-) diff --git a/ts/components/session/ActionsPanel.tsx b/ts/components/session/ActionsPanel.tsx index 6b7ad7529..284d7af51 100644 --- a/ts/components/session/ActionsPanel.tsx +++ b/ts/components/session/ActionsPanel.tsx @@ -155,7 +155,7 @@ const triggerSyncIfNeeded = async () => { const doAppStartUp = (dispatch: Dispatch) => { if (window.lokiFeatureFlags.useOnionRequests || window.lokiFeatureFlags.useFileOnionRequests) { // Initialize paths for onion requests - void OnionPaths.buildNewOnionPaths(); + void OnionPaths.buildNewOnionPathsOneAtATime(); } // init the messageQueue. In the constructor, we add all not send messages diff --git a/ts/session/onions/onionPath.ts b/ts/session/onions/onionPath.ts index c4c767f05..e6b747296 100644 --- a/ts/session/onions/onionPath.ts +++ b/ts/session/onions/onionPath.ts @@ -24,9 +24,8 @@ const pathFailureThreshold = 3; // so using GuardNode would not be correct (there is // some naming issue here it seems) let guardNodes: Array = []; -let onionRequestCounter = 0; // Request index for debugging -export async function buildNewOnionPaths() { +export async function buildNewOnionPathsOneAtATime() { // this function may be called concurrently make sure we only have one inflight return allowOnlyOneAtATime('buildNewOnionPaths', async () => { await buildNewOnionPathsWorker(); @@ -53,9 +52,7 @@ export async function dropSnodeFromPath(snodeEd25519: string) { if (pathWithSnodeIndex === -1) { return; } - window.log.info( - `dropping snode (...${snodeEd25519.substr(58)}) from path index: ${pathWithSnodeIndex}` - ); + window.log.info(`dropping snode ${snodeEd25519} from path index: ${pathWithSnodeIndex}`); // make a copy now so we don't alter the real one while doing stuff here const oldPaths = _.cloneDeep(onionPaths); @@ -84,11 +81,11 @@ export async function getOnionPath(toExclude?: SnodePool.Snode): Promise p[0].pubkey_ed25519 === ed25519Key); + const failingPathIndex = onionPaths.findIndex(p => p[0].pubkey_ed25519 === guardNodeEd25519); if (failingPathIndex === -1) { - console.warn('No such path starts with this guard node '); + debugger; + window.log.warn('No such path starts with this guard node '); return; } - onionPaths = onionPaths.filter(p => p[0].pubkey_ed25519 !== ed25519Key); + onionPaths = onionPaths.filter(p => p[0].pubkey_ed25519 !== guardNodeEd25519); - const edKeys = guardNodes.filter(g => g.pubkey_ed25519 !== ed25519Key).map(n => n.pubkey_ed25519); + const edKeys = guardNodes + .filter(g => g.pubkey_ed25519 !== guardNodeEd25519) + .map(n => n.pubkey_ed25519); - guardNodes = guardNodes.filter(g => g.pubkey_ed25519 !== ed25519Key); - pathFailureCount[ed25519Key] = 0; + guardNodes = guardNodes.filter(g => g.pubkey_ed25519 !== guardNodeEd25519); + pathFailureCount[guardNodeEd25519] = 0; // write the updates guard nodes to the db. // the next call to getOnionPath will trigger a rebuild of the path await updateGuardNodes(edKeys); } -export function assignOnionRequestNumber() { - onionRequestCounter += 1; - return onionRequestCounter; -} - async function testGuardNode(snode: SnodePool.Snode) { const { log } = window; @@ -317,7 +316,8 @@ async function buildNewOnionPathsWorker() { 'LokiSnodeAPI::buildNewOnionPaths - Too few nodes to build an onion path! Refreshing pool and retrying' ); await SnodePool.refreshRandomPool(); - await buildNewOnionPaths(); + debugger; + await buildNewOnionPathsOneAtATime(); return; } @@ -345,6 +345,8 @@ async function buildNewOnionPathsWorker() { } onionPaths.push(path); } + console.warn('guards', guards); + console.warn('onionPaths', onionPaths); log.info(`Built ${onionPaths.length} onion paths`); } diff --git a/ts/session/onions/onionSend.ts b/ts/session/onions/onionSend.ts index 6bc87eb1e..48c10843c 100644 --- a/ts/session/onions/onionSend.ts +++ b/ts/session/onions/onionSend.ts @@ -13,6 +13,7 @@ import _, { toNumber } from 'lodash'; import { default as insecureNodeFetch } from 'node-fetch'; import { PROTOCOLS } from '../constants'; import { toHex } from '../utils/String'; +import pRetry from 'p-retry'; // FIXME: replace with something on urlPubkeyMap... const FILESERVER_HOSTS = [ @@ -22,8 +23,6 @@ const FILESERVER_HOSTS = [ 'file.getsession.org', ]; -const MAX_SEND_ONION_RETRIES = 3; - type OnionFetchOptions = { method: string; body?: string; @@ -32,45 +31,17 @@ type OnionFetchOptions = { type OnionFetchBasicOptions = { retry?: number; - requestNumber?: number; noJson?: boolean; - counter?: number; }; -const handleSendViaOnionRetry = async ( - result: RequestError, - options: OnionFetchBasicOptions, - srvPubKey: string, - url: URL, - fetchOptions: OnionFetchOptions, - abortSignal?: AbortSignal -) => { - window.log.error('sendOnionRequestLsrpcDest() returned a RequestError: ', result); - - if (options.retry && options.retry >= MAX_SEND_ONION_RETRIES) { - window.log.error(`sendViaOnion too many retries: ${options.retry}. Stopping retries.`); - return null; - } else { - // handle error/retries, this is a RequestError - window.log.error( - `sendViaOnion #${options.requestNumber} - Retry #${options.retry} Couldnt handle onion request, retrying` - ); - } - // retry the same request, and increment the counter - return sendViaOnion( - srvPubKey, - url, - fetchOptions, - { - ...options, - retry: (options.retry as number) + 1, - counter: options.requestNumber, - }, - abortSignal - ); +type OnionPayloadObj = { + method: string; + endpoint: string; + body: any; + headers: Record; }; -const buildSendViaOnionPayload = (url: URL, fetchOptions: OnionFetchOptions) => { +const buildSendViaOnionPayload = (url: URL, fetchOptions: OnionFetchOptions): OnionPayloadObj => { let tempHeaders = fetchOptions.headers || {}; const payloadObj = { method: fetchOptions.method || 'GET', @@ -103,15 +74,15 @@ const buildSendViaOnionPayload = (url: URL, fetchOptions: OnionFetchOptions) => return payloadObj; }; -export const getOnionPathForSending = async (requestNumber: number) => { +export const getOnionPathForSending = async () => { let pathNodes: Array = []; try { pathNodes = await OnionPaths.getOnionPath(); } catch (e) { - window.log.error(`sendViaOnion #${requestNumber} - getOnionPath Error ${e.code} ${e.message}`); + window.log.error(`sendViaOnion - getOnionPath Error ${e.code} ${e.message}`); } if (!pathNodes?.length) { - window.log.warn(`sendViaOnion #${requestNumber} - failing, no path available`); + window.log.warn('sendViaOnion - failing, no path available'); // should we retry? return null; } @@ -121,11 +92,40 @@ export const getOnionPathForSending = async (requestNumber: number) => { const initOptionsWithDefaults = (options: OnionFetchBasicOptions) => { const defaultFetchBasicOptions = { retry: 0, - requestNumber: OnionPaths.assignOnionRequestNumber(), }; return _.defaults(options, defaultFetchBasicOptions); }; +const sendViaOnionRetryable = async ({ + castedDestinationX25519Key, + finalRelayOptions, + payloadObj, + abortSignal, +}: { + castedDestinationX25519Key: string; + finalRelayOptions: FinalRelayOptions; + payloadObj: OnionPayloadObj; + abortSignal?: AbortSignal; +}) => { + const pathNodes = await getOnionPathForSending(); + + if (!pathNodes) { + throw new Error('getOnionPathForSending is emtpy'); + } + + // this call throws a normal error (which will trigger a retry) if a retryable is got (bad path or whatever) + // it throws an AbortError in case the retry should not be retried again (aborted, or ) + const result = await sendOnionRequestLsrpcDest( + pathNodes, + castedDestinationX25519Key, + finalRelayOptions, + payloadObj, + abortSignal + ); + + return result; +}; + /** * FIXME the type for this is not correct for open group api v2 returned values * result is status_code and whatever the body should be @@ -151,61 +151,48 @@ export const sendViaOnion = async ( const defaultedOptions = initOptionsWithDefaults(options); const payloadObj = buildSendViaOnionPayload(url, fetchOptions); - const pathNodes = await getOnionPathForSending(defaultedOptions.requestNumber); - if (!pathNodes) { - return null; + // if protocol is forced to 'http:' => just use http (without the ':'). + // otherwise use https as protocol (this is the default) + const forcedHttp = url.protocol === PROTOCOLS.HTTP; + const finalRelayOptions: FinalRelayOptions = { + host: url.hostname, + }; + + if (forcedHttp) { + finalRelayOptions.protocol = 'http'; + } + if (forcedHttp) { + finalRelayOptions.port = url.port ? toNumber(url.port) : 80; } - // do the request - let result: SnodeResponse | RequestError; + let result: SnodeResponse; try { - // if protocol is forced to 'http:' => just use http (without the ':'). - // otherwise use https as protocol (this is the default) - const forcedHttp = url.protocol === PROTOCOLS.HTTP; - const finalRelayOptions: FinalRelayOptions = { - host: url.hostname, - }; - - if (forcedHttp) { - finalRelayOptions.protocol = 'http'; - } - if (forcedHttp) { - finalRelayOptions.port = url.port ? toNumber(url.port) : 80; - } - - result = await sendOnionRequestLsrpcDest( - 0, - pathNodes, - castedDestinationX25519Key, - finalRelayOptions, - payloadObj, - defaultedOptions.requestNumber, - abortSignal + result = await pRetry( + async () => { + return sendViaOnionRetryable({ + castedDestinationX25519Key, + finalRelayOptions, + payloadObj, + abortSignal, + }); + }, + { + retries: 5, + factor: 1, + minTimeout: 1000, + onFailedAttempt: e => { + window.log.warn( + `sendViaOnionRetryable attempt #${e.attemptNumber} failed. ${e.retriesLeft} retries left...` + ); + }, + } ); } catch (e) { - window.log.error('sendViaOnion - lokiRpcUtils error', e.code, e.message); + window.log.warn('sendViaOnionRetryable failed ', e); + console.warn('error to show to user', e); return null; } - // RequestError return type is seen as number (as it is an enum) - if (typeof result === 'string') { - console.warn('above string type is not correct'); - if (result === RequestError.ABORTED) { - window.log.info('sendViaOnion aborted. not retrying'); - return null; - } - const retriedResult = await handleSendViaOnionRetry( - result, - defaultedOptions, - castedDestinationX25519Key, - url, - fetchOptions, - abortSignal - ); - // keep the await separate so we can log it easily - return retriedResult; - } - // If we expect something which is not json, just return the body we got. if (defaultedOptions.noJson) { return { @@ -226,11 +213,7 @@ export const sendViaOnion = async ( try { body = JSON.parse(result.body); } catch (e) { - window.log.error( - `sendViaOnion #${defaultedOptions.requestNumber} - Can't decode JSON body`, - typeof result.body, - result.body - ); + window.log.error("sendViaOnion Can't decode JSON body", typeof result.body, result.body); } } // result.status has the http response code @@ -251,9 +234,7 @@ type ServerRequestOptionsType = { forceFreshToken?: boolean; retry?: number; - requestNumber?: number; noJson?: boolean; - counter?: number; }; // tslint:disable-next-line: max-func-body-length diff --git a/ts/session/sending/LokiMessageApi.ts b/ts/session/sending/LokiMessageApi.ts index be17a6cbc..21c18ea1e 100644 --- a/ts/session/sending/LokiMessageApi.ts +++ b/ts/session/sending/LokiMessageApi.ts @@ -50,8 +50,8 @@ export async function sendMessage( // send parameters const params = { pubKey, - ttl: ttl.toString(), - timestamp: messageTimeStamp.toString(), + ttl: `${ttl}`, + timestamp: `${messageTimeStamp}`, data: data64, }; diff --git a/ts/session/snode_api/SNodeAPI.ts b/ts/session/snode_api/SNodeAPI.ts index 40af3c174..cccbf78b4 100644 --- a/ts/session/snode_api/SNodeAPI.ts +++ b/ts/session/snode_api/SNodeAPI.ts @@ -1,7 +1,6 @@ // we don't throw or catch here import { default as insecureNodeFetch } from 'node-fetch'; import https from 'https'; -import crypto from 'crypto'; import fs from 'fs'; import path from 'path'; @@ -11,26 +10,13 @@ import Electron from 'electron'; const { remote } = Electron; import { snodeRpc } from './lokiRpc'; -import { sendOnionRequestLsrpcDest, SnodeResponse } from './onions'; - -export { sendOnionRequestLsrpcDest }; - -import { - getRandomSnode, - getRandomSnodePool, - getSwarmFor, - requiredSnodesForAgreement, - Snode, - updateSwarmFor, -} from './snodePool'; + +import { getRandomSnode, getRandomSnodePool, requiredSnodesForAgreement, Snode } from './snodePool'; import { Constants } from '..'; -import { sleepFor } from '../utils/Promise'; import { sha256 } from '../crypto'; import pRetry from 'p-retry'; import _ from 'lodash'; -const maxAcceptableFailuresStoreOnNode = 10; - const getSslAgentForSeedNode = (seedNodeHost: string, isSsl = false) => { let filePrefix = ''; let pubkey256 = ''; @@ -290,6 +276,11 @@ export async function getSnodePoolFromSnodes() { retries: 3, factor: 1, minTimeout: 1000, + onFailedAttempt: e => { + window.log.warn( + `getSnodePoolFromSnode attempt #${e.attemptNumber} failed. ${e.retriesLeft} retries left...` + ); + }, } ); }) diff --git a/ts/session/snode_api/onions.ts b/ts/session/snode_api/onions.ts index d3ed77b0b..8fecb0a8c 100644 --- a/ts/session/snode_api/onions.ts +++ b/ts/session/snode_api/onions.ts @@ -11,6 +11,7 @@ import ByteBuffer from 'bytebuffer'; import { OnionPaths } from '../onions'; import { fromBase64ToArrayBuffer, toHex } from '../utils/String'; import pRetry from 'p-retry'; +import { incrementBadPathCountOrDrop } from '../onions/onionPath'; export enum RequestError { BAD_PATH = 'BAD_PATH', @@ -102,8 +103,7 @@ async function buildOnionCtxs( nodePath: Array, destCtx: DestinationContext, targetED25519Hex?: string, - finalRelayOptions?: FinalRelayOptions, - id = '' + finalRelayOptions?: FinalRelayOptions ) { const { log } = window; @@ -142,7 +142,7 @@ async function buildOnionCtxs( pubkeyHex = nodePath[i + 1].pubkey_ed25519; if (!pubkeyHex) { log.error( - `loki_rpc:::buildOnionGuardNodePayload ${id} - no ed25519 for`, + 'loki_rpc:::buildOnionGuardNodePayload - no ed25519 for', nodePath[i + 1], 'path node', i + 1 @@ -160,7 +160,7 @@ async function buildOnionCtxs( ctxes.push(ctx); } catch (e) { log.error( - `loki_rpc:::buildOnionGuardNodePayload ${id} - encryptForRelayV2 failure`, + 'loki_rpc:::buildOnionGuardNodePayload - encryptForRelayV2 failure', e.code, e.message ); @@ -177,10 +177,9 @@ async function buildOnionGuardNodePayload( nodePath: Array, destCtx: DestinationContext, targetED25519Hex?: string, - finalRelayOptions?: FinalRelayOptions, - id = '' + finalRelayOptions?: FinalRelayOptions ) { - const ctxes = await buildOnionCtxs(nodePath, destCtx, targetED25519Hex, finalRelayOptions, id); + const ctxes = await buildOnionCtxs(nodePath, destCtx, targetED25519Hex, finalRelayOptions); // this is the OUTER side of the onion, the one encoded with multiple layer // So the one we will send to the first guard node. @@ -195,53 +194,78 @@ async function buildOnionGuardNodePayload( return encodeCiphertextPlusJson(guardCtx.ciphertext, guardPayloadObj); } -// Process a response as it arrives from `fetch`, handling -// http errors and attempting to decrypt the body with `sharedKey` -// May return false BAD_PATH, indicating that we should try a new path. -// tslint:disable-next-line: cyclomatic-complexity -async function processOnionResponse( - reqIdx: number, - response: Response, - symmetricKey: ArrayBuffer, - debug: boolean, - abortSignal?: AbortSignal, - associatedWith?: string -): Promise { - let ciphertext = ''; - - try { - ciphertext = await response.text(); - } catch (e) { - window.log.warn(e); - } - - if (abortSignal?.aborted) { - window.log.warn(`(${reqIdx}) [path] Call aborted`); - // this will make the pRetry stop - throw new pRetry.AbortError('Request got aborted'); - } - - if (response.status === 406) { +function process406Error(statusCode: number) { + if (statusCode === 406) { // clock out of sync - console.warn('clocko ut of sync todo'); + console.warn('clock out of sync todo'); // this will make the pRetry stop throw new pRetry.AbortError('You clock is out of sync with the network. Check your clock.'); } +} - if (response.status === 421) { - // clock out of sync +async function process421Error( + statusCode: number, + body: string, + associatedWith?: string, + lsrpcEd25519Key?: string +) { + if (statusCode === 421) { + if (!lsrpcEd25519Key || !associatedWith) { + throw new Error('status 421 without a final destination or no associatedWith makes no sense'); + } window.log.info('Invalidating swarm'); + await handle421InvalidSwarm(lsrpcEd25519Key, body, associatedWith); + } +} + +/** + * Handle throwing errors for destination errors. + * A destination can either be a server (like an opengroup server) in this case destinationEd25519 is unset or be a snode (for snode rpc calls) and destinationEd25519 is set in this case. + * + * If destinationEd25519 is set, we will increment the failure count of the specified snode + */ +async function processOnionRequestErrorAtDestination({ + statusCode, + body, + destinationEd25519, + associatedWith, +}: { + statusCode: number; + body: string; + destinationEd25519?: string; + associatedWith?: string; +}) { + if (statusCode === 200) { + window.log.info('processOnionRequestErrorAtDestination. statusCode ok:', statusCode); + return; } + process406Error(statusCode); + await process421Error(statusCode, body, associatedWith, destinationEd25519); + if (destinationEd25519) { + await processAnyOtherErrorAtDestination(statusCode, destinationEd25519, associatedWith); + } else { + console.warn( + 'processOnionRequestErrorAtDestination: destinationEd25519 unset. was it a group call?', + statusCode + ); + } +} +async function processAnyOtherErrorOnPath( + status: number, + guardNodeEd25519: string, + ciphertext?: string, + associatedWith?: string +) { // this test checks for on error in your path. if ( // response.status === 502 || // response.status === 503 || // response.status === 504 || // response.status === 404 || - response.status !== 200 // this is pretty strong. a 400 (Oxen server error) will be handled as a bad path. + status !== 200 // this is pretty strong. a 400 (Oxen server error) will be handled as a bad path. ) { - window.log.warn(`(${reqIdx}) [path] Got status: ${response.status}`); + window.log.warn(`[path] Got status: ${status}`); // const prefix = 'Next node not found: '; let nodeNotFound; @@ -251,12 +275,94 @@ async function processOnionResponse( // If we have a specific node in fault we can exclude just this node. // Otherwise we increment the whole path failure count - await handleOnionRequestErrors(response.status, nodeNotFound, body || '', associatedWith); + if (nodeNotFound) { + await incrementBadSnodeCountOrDrop(nodeNotFound, associatedWith); + } else { + await incrementBadPathCountOrDrop(guardNodeEd25519); + } + throw new Error(`Bad Path handled. Retry this request. Status: ${status}`); + } +} + +async function processAnyOtherErrorAtDestination( + status: number, + destinationEd25519: string, + associatedWith?: string +) { + // this test checks for on error in your path. + if ( + // response.status === 502 || + // 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. + ) { + window.log.warn(`[path] Got status at destination: ${status}`); + + await incrementBadSnodeCountOrDrop(destinationEd25519, associatedWith); + + throw new Error(`Bad Path handled. Retry this request. Status: ${status}`); + } +} + +async function processOnionRequestErrorOnPath( + response: Response, + ciphertext: string, + guardNodeEd25519: string, + lsrpcEd25519Key?: string, + associatedWith?: string +) { + if (response.status !== 200) { + console.warn('errorONpath:', ciphertext); + } + process406Error(response.status); + await process421Error(response.status, ciphertext, associatedWith, lsrpcEd25519Key); + await processAnyOtherErrorOnPath(response.status, guardNodeEd25519, ciphertext, associatedWith); +} + +function processAbortedRequest(abortSignal?: AbortSignal) { + if (abortSignal?.aborted) { + window.log.warn('[path] Call aborted'); + // this will make the pRetry stop + throw new pRetry.AbortError('Request got aborted'); + } +} + +const debug = false; + +// Process a response as it arrives from `fetch`, handling +// http errors and attempting to decrypt the body with `sharedKey` +// May return false BAD_PATH, indicating that we should try a new path. +// tslint:disable-next-line: cyclomatic-complexity +async function processOnionResponse( + response: Response, + symmetricKey: ArrayBuffer, + guardNode: Snode, + lsrpcEd25519Key?: string, + abortSignal?: AbortSignal, + associatedWith?: string +): Promise { + let ciphertext = ''; + + processAbortedRequest(abortSignal); + + try { + ciphertext = await response.text(); + } catch (e) { + window.log.warn(e); } + await processOnionRequestErrorOnPath( + response, + ciphertext, + guardNode.pubkey_ed25519, + lsrpcEd25519Key, + associatedWith + ); + if (!ciphertext) { window.log.warn( - `(${reqIdx}) [path] lokiRpc::processingOnionResponse - Target node return empty ciphertext` + '[path] lokiRpc::processingOnionResponse - Target node return empty ciphertext' ); throw new Error('Target node return empty ciphertext'); } @@ -278,14 +384,11 @@ async function processOnionResponse( ); plaintext = new TextDecoder().decode(plaintextBuffer); } catch (e) { - window.log.error(`(${reqIdx}) [path] lokiRpc::processingOnionResponse - decode error`, e); - window.log.error( - `(${reqIdx}) [path] lokiRpc::processingOnionResponse - symmetricKey`, - toHex(symmetricKey) - ); + window.log.error('[path] lokiRpc::processingOnionResponse - decode error', e); + window.log.error('[path] lokiRpc::processingOnionResponse - symmetricKey', toHex(symmetricKey)); if (ciphertextBuffer) { window.log.error( - `(${reqIdx}) [path] lokiRpc::processingOnionResponse - ciphertextBuffer`, + '[path] lokiRpc::processingOnionResponse - ciphertextBuffer', toHex(ciphertextBuffer) ); } @@ -302,18 +405,22 @@ async function processOnionResponse( window.log.warn('Received an out of bounds js number'); } return value; + }) as Record; + + const status = jsonRes.status_code || jsonRes.status; + await processOnionRequestErrorAtDestination({ + statusCode: status, + body: ciphertext, + destinationEd25519: lsrpcEd25519Key, + associatedWith, }); - if (jsonRes.status_code) { - jsonRes.status = jsonRes.status_code; - } - return jsonRes as SnodeResponse; } catch (e) { window.log.error( - `(${reqIdx}) [path] lokiRpc::processingOnionResponse - parse error outer json ${e.code} ${e.message} json: '${plaintext}'` + `[path] lokiRpc::processingOnionResponse - parse error outer json ${e.code} ${e.message} json: '${plaintext}'` ); - throw new Error('Parsing error on outer json'); + throw e; } } @@ -376,31 +483,6 @@ async function handle421InvalidSwarm(snodeEd25519: string, body: string, associa window.log.warn('Got a 421 without an associatedWith publickey'); } -/** - * 406 => clock out of sync - * 421 => swarm changed for this associatedWith publicKey - * 500, 502, 503, AND default => bad snode. - */ -async function handleOnionRequestErrors( - statusCode: number, - snodeEd25519: string, - body: string, - associatedWith?: string -) { - switch (statusCode) { - case 406: - // FIXME audric - console.warn('Clockoutofsync TODO'); - window.log.warn('The users clock is out of sync with the service node network.'); - throw new Error('ClockOutOfSync TODO'); - // return ClockOutOfSync; - case 421: - return handle421InvalidSwarm(snodeEd25519, body, associatedWith); - default: - return incrementBadSnodeCountOrDrop(snodeEd25519, associatedWith); - } -} - /** * Handle a bad snode result. * The `snodeFailureCount` for that node is incremented. If it's more than `snodeFailureThreshold`, @@ -422,10 +504,10 @@ export async function incrementBadSnodeCountOrDrop(snodeEd25519: string, associa if (newFailureCount >= snodeFailureThreshold) { window.log.warn(`Failure threshold reached for: ${snodeEd25519}; dropping it.`); if (associatedWith) { - console.warn(`Dropping ${snodeEd25519} from swarm of ${associatedWith}`); + window.log.info(`Dropping ${snodeEd25519} from swarm of ${associatedWith}`); await dropSnodeFromSwarmIfNeeded(associatedWith, snodeEd25519); } - console.warn(`Dropping ${snodeEd25519} from snodepool`); + window.log.info(`Dropping ${snodeEd25519} from snodepool`); dropSnodeFromSnodePool(snodeEd25519); // the snode was ejected from the pool so it won't be used again. @@ -435,7 +517,10 @@ export async function incrementBadSnodeCountOrDrop(snodeEd25519: string, associa try { await OnionPaths.dropSnodeFromPath(snodeEd25519); } catch (e) { - console.warn('dropSnodeFromPath, patchingup', e); + window.log.warn( + 'dropSnodeFromPath, got error while patchingup... incrementing the whole path as bad', + e + ); // if dropSnodeFromPath throws, it means there is an issue patching up the path, increment the whole path issues count await OnionPaths.incrementBadPathCountOrDrop(snodeEd25519); } @@ -447,16 +532,13 @@ export async function incrementBadSnodeCountOrDrop(snodeEd25519: string, associa * But the caller needs to handle the retry (and rebuild the path on his side if needed) */ const sendOnionRequestHandlingSnodeEject = async ({ - reqIdx, destX25519Any, finalDestOptions, nodePath, abortSignal, associatedWith, finalRelayOptions, - lsrpcIdx, }: { - reqIdx: number; nodePath: Array; destX25519Any: string; finalDestOptions: { @@ -465,27 +547,24 @@ const sendOnionRequestHandlingSnodeEject = async ({ body?: string; }; finalRelayOptions?: FinalRelayOptions; - lsrpcIdx?: number; abortSignal?: AbortSignal; associatedWith?: string; }): Promise => { const { response, decodingSymmetricKey } = await sendOnionRequest({ - reqIdx, nodePath, destX25519Any, finalDestOptions, finalRelayOptions, - lsrpcIdx, 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( - reqIdx, response, decodingSymmetricKey, - false, + nodePath[0], + finalDestOptions?.destination_ed25519_hex, abortSignal, associatedWith ); @@ -505,15 +584,12 @@ const sendOnionRequestHandlingSnodeEject = async ({ * @param finalRelayOptions those are the options 3 will use to make a request to R. It contains for instance the host to make the request to */ const sendOnionRequest = async ({ - reqIdx, nodePath, destX25519Any, finalDestOptions, finalRelayOptions, - lsrpcIdx, abortSignal, }: { - reqIdx: number; nodePath: Array; destX25519Any: string; finalDestOptions: { @@ -522,19 +598,10 @@ const sendOnionRequest = async ({ body?: string; }; finalRelayOptions?: FinalRelayOptions; - lsrpcIdx?: number; abortSignal?: AbortSignal; }) => { const { log } = window; - let id = ''; - if (lsrpcIdx !== undefined) { - id += `${lsrpcIdx}=>`; - } - if (reqIdx !== undefined) { - id += `${reqIdx}`; - } - // get destination pubkey in array buffer format let destX25519hex = destX25519Any; if (typeof destX25519hex !== 'string') { @@ -575,7 +642,7 @@ const sendOnionRequest = async ({ } } catch (e) { log.error( - `loki_rpc::sendOnionRequest ${id} - encryptForPubKey failure [`, + 'loki_rpc::sendOnionRequest - encryptForPubKey failure [', e.code, e.message, '] destination X25519', @@ -592,8 +659,7 @@ const sendOnionRequest = async ({ nodePath, destCtx, targetEd25519hex, - finalRelayOptions, - id + finalRelayOptions ); const guardNode = nodePath[0]; @@ -615,14 +681,12 @@ const sendOnionRequest = async ({ }; async function sendOnionRequestSnodeDest( - reqIdx: any, onionPath: Array, targetNode: Snode, plaintext?: string, associatedWith?: string ) { return sendOnionRequestHandlingSnodeEject({ - reqIdx, nodePath: onionPath, destX25519Any: targetNode.pubkey_x25519, finalDestOptions: { @@ -638,21 +702,17 @@ async function sendOnionRequestSnodeDest( * But the caller needs to handle the retry (and rebuild the path on his side if needed) */ export async function sendOnionRequestLsrpcDest( - reqIdx: number, onionPath: Array, destX25519Any: string, finalRelayOptions: FinalRelayOptions, payloadObj: FinalDestinationOptions, - lsrpcIdx: number, abortSignal?: AbortSignal -): Promise { +): Promise { return sendOnionRequestHandlingSnodeEject({ - reqIdx, nodePath: onionPath, destX25519Any, finalDestOptions: payloadObj, finalRelayOptions, - lsrpcIdx, abortSignal, }); } @@ -663,16 +723,12 @@ export function getPathString(pathObjArr: Array<{ ip: string; port: number }>): async function onionFetchRetryable( targetNode: Snode, - requestId: number, body?: string, associatedWith?: string ): Promise { - const { log } = window; - // Get a path excluding `targetNode`: - // eslint-disable no-await-in-loop const path = await OnionPaths.getOnionPath(targetNode); - const result = await sendOnionRequestSnodeDest(requestId, path, targetNode, body, associatedWith); + const result = await sendOnionRequestSnodeDest(path, targetNode, body, associatedWith); return result; } @@ -684,24 +740,27 @@ export async function lokiOnionFetch( body?: string, associatedWith?: string ): Promise { - // Get a path excluding `targetNode`: - const thisIdx = OnionPaths.assignOnionRequestNumber(); - try { const retriedResult = await pRetry( async () => { - return onionFetchRetryable(targetNode, thisIdx, body, associatedWith); + return onionFetchRetryable(targetNode, body, associatedWith); }, { retries: 5, factor: 1, minTimeout: 1000, + onFailedAttempt: e => { + window.log.warn( + `onionFetchRetryable attempt #${e.attemptNumber} failed. ${e.retriesLeft} retries left...` + ); + }, } ); return retriedResult; } catch (e) { - window.log.warn('onionFetchRetryable failed '); + window.log.warn('onionFetchRetryable failed ', e); + console.warn('error to show to user'); return undefined; } } diff --git a/ts/session/snode_api/snodePool.ts b/ts/session/snode_api/snodePool.ts index f58259715..f65826113 100644 --- a/ts/session/snode_api/snodePool.ts +++ b/ts/session/snode_api/snodePool.ts @@ -112,11 +112,14 @@ async function tryGetSnodeListFromLokidSeednode(seedNodes: Array): Pro * @param snodeEd25519 the snode ed25519 to drop from the snode pool */ export function dropSnodeFromSnodePool(snodeEd25519: string) { - _.remove(randomSnodePool, x => x.pubkey_ed25519 === snodeEd25519); + const exists = _.some(randomSnodePool, x => x.pubkey_ed25519 === snodeEd25519); + if (exists) { + _.remove(randomSnodePool, x => x.pubkey_ed25519 === snodeEd25519); - window.log.warn( - `Marking ${snodeEd25519} as unreachable, ${randomSnodePool.length} snodes remaining in randomPool` - ); + window.log.warn( + `Marking ${snodeEd25519} as unreachable, ${randomSnodePool.length} snodes remaining in randomPool` + ); + } } /** @@ -284,6 +287,11 @@ export async function refreshRandomPool(): Promise { retries: 2, factor: 1, minTimeout: 1000, + onFailedAttempt: e => { + window.log.warn( + `getSnodePoolFromSnodes attempt #${e.attemptNumber} failed. ${e.retriesLeft} retries left...` + ); + }, } ); } catch (e) {