WIP

ts/components/session/ActionsPanel.tsx

@@ -155,7 +155,7 @@ const triggerSyncIfNeeded = async () => {
 const doAppStartUp = (dispatch: Dispatch<any>) => {
   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

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<SnodePool.Snode> = [];
-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<Array<S
   let attemptNumber = 0;
   while (onionPaths.length < minimumGuardCount) {
     log.error(
-      `Must have at least 2 good onion paths, actual: ${onionPaths.length}, attempt #${attemptNumber} fetching more...`
+      `Must have at least ${minimumGuardCount} good onion paths, actual: ${onionPaths.length}, attempt #${attemptNumber} fetching more...`
     );
     // eslint-disable-next-line no-await-in-loop
-    await buildNewOnionPaths();
-    // should we add a delay? buildNewOnionPaths should act as one
+    await buildNewOnionPathsOneAtATime();
+    // should we add a delay? buildNewOnionPathsOneAtATime should act as one
 
     // reload goodPaths now
     attemptNumber += 1;
@@ -130,9 +127,13 @@ export async function incrementBadPathCountOrDrop(guardNodeEd25519: string) {
 
   window.log.info('handling bad path for path index', pathIndex);
   const oldPathFailureCount = pathFailureCount[guardNodeEd25519] || 0;
+
+  // tslint:disable: prefer-for-of
+
   const newPathFailureCount = oldPathFailureCount + 1;
-  // tslint:disable-next-line: prefer-for-of
-  for (let index = 0; index < pathWithIssues.length; index++) {
+  // skip the first one as the first one is the guard node.
+  // a guard node is dropped when the path is dropped completely (in dropPathStartingWithGuardNode)
+  for (let index = 1; index < pathWithIssues.length; index++) {
     const snode = pathWithIssues[index];
     await incrementBadSnodeCountOrDrop(snode.pubkey_ed25519);
   }
@@ -149,30 +150,28 @@ export async function incrementBadPathCountOrDrop(guardNodeEd25519: string) {
  * It writes to the db the updated list of guardNodes.
  * @param ed25519Key the guard node ed25519 pubkey
  */
-async function dropPathStartingWithGuardNode(ed25519Key: string) {
+async function dropPathStartingWithGuardNode(guardNodeEd25519: string) {
   // we are dropping it. Reset the counter in case this same guard gets choosen later
-  const failingPathIndex = onionPaths.findIndex(p => 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`);
 }

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<string, any>;
 };
 
-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<Snode> = [];
   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

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,
   };
 

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...`
+            );
+          },
         }
       );
     })

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<Snode>,
   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<Snode>,
   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<SnodeResponse> {
-  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<SnodeResponse> {
+  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<string, any>;
+
+    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<Snode>;
   destX25519Any: string;
   finalDestOptions: {
@@ -465,27 +547,24 @@ const sendOnionRequestHandlingSnodeEject = async ({
     body?: string;
   };
   finalRelayOptions?: FinalRelayOptions;
-  lsrpcIdx?: number;
   abortSignal?: AbortSignal;
   associatedWith?: string;
 }): Promise<SnodeResponse> => {
   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<Snode>;
   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<Snode>,
   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<Snode>,
   destX25519Any: string,
   finalRelayOptions: FinalRelayOptions,
   payloadObj: FinalDestinationOptions,
-  lsrpcIdx: number,
   abortSignal?: AbortSignal
-): Promise<SnodeResponse | RequestError> {
+): Promise<SnodeResponse> {
   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<SnodeResponse> {
-  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<SnodeResponse | undefined> {
-  // 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;
   }
 }

ts/session/snode_api/snodePool.ts

@@ -112,11 +112,14 @@ async function tryGetSnodeListFromLokidSeednode(seedNodes: Array<SeedNode>): 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<void> {
           retries: 2,
           factor: 1,
           minTimeout: 1000,
+          onFailedAttempt: e => {
+            window.log.warn(
+              `getSnodePoolFromSnodes attempt #${e.attemptNumber} failed. ${e.retriesLeft} retries left...`
+            );
+          },
         }
       );
     } catch (e) {