From fea679fe79812f0d669402d55f65c82d18b3c949 Mon Sep 17 00:00:00 2001
From: Ryan Tharp <neuro@interx.net>
Date: Tue, 24 Mar 2020 21:58:48 -0700
Subject: [PATCH 01/15] sendToProxy use getRandomProxySnodeAddress, retry with
 options

---
 js/modules/loki_app_dot_net_api.js | 12 ++++++++++--
 1 file changed, 10 insertions(+), 2 deletions(-)

diff --git a/js/modules/loki_app_dot_net_api.js b/js/modules/loki_app_dot_net_api.js
index 945ec66a5..5b4db12b6 100644
--- a/js/modules/loki_app_dot_net_api.js
+++ b/js/modules/loki_app_dot_net_api.js
@@ -32,6 +32,8 @@ const snodeHttpsAgent = new https.Agent({
   rejectUnauthorized: false,
 });
 
+const timeoutDelay = ms => new Promise(resolve => setTimeout(resolve, ms));
+
 const sendToProxy = async (
   srvPubKey,
   endpoint,
@@ -44,7 +46,13 @@ const sendToProxy = async (
     );
     return {};
   }
-  const randSnode = await lokiSnodeAPI.getRandomSnodeAddress();
+  // use nodes that support more than 1mb
+  const randSnode = await lokiSnodeAPI.getRandomProxySnodeAddress();
+  if (randSnode === false) {
+    // no nodes in the pool yet, give it some time and retry
+    await timeoutDelay(1000);
+    return sendToProxy(srvPubKey, endpoint, pFetchOptions, options);
+  }
   const url = `https://${randSnode.ip}:${randSnode.port}/file_proxy`;
 
   const fetchOptions = pFetchOptions; // make lint happy
@@ -138,7 +146,7 @@ const sendToProxy = async (
     );
     // retry (hopefully with new snode)
     // FIXME: max number of retries...
-    return sendToProxy(srvPubKey, endpoint, fetchOptions);
+    return sendToProxy(srvPubKey, endpoint, fetchOptions, options);
   }
 
   let response = {};

From 330b2b1b16ed6261629524a8588382b3626ad847 Mon Sep 17 00:00:00 2001
From: Ryan Tharp <neuro@interx.net>
Date: Tue, 24 Mar 2020 21:59:36 -0700
Subject: [PATCH 02/15] sort random pool into versions,
 getRandomProxySnodeAddress to use 2.0.2 or newer versions

---
 js/modules/loki_snode_api.js | 62 ++++++++++++++++++++++++++++++++++++
 1 file changed, 62 insertions(+)

diff --git a/js/modules/loki_snode_api.js b/js/modules/loki_snode_api.js
index 8709f2a4b..5f47bab8e 100644
--- a/js/modules/loki_snode_api.js
+++ b/js/modules/loki_snode_api.js
@@ -3,7 +3,13 @@
 
 const is = require('@sindresorhus/is');
 const { lokiRpc } = require('./loki_rpc');
+const https = require('https');
 const nodeFetch = require('node-fetch');
+const semver = require('semver');
+
+const snodeHttpsAgent = new https.Agent({
+  rejectUnauthorized: false,
+});
 
 const RANDOM_SNODES_TO_USE_FOR_PUBKEY_SWARM = 3;
 const SEED_NODE_RETRIES = 3;
@@ -18,6 +24,7 @@ class LokiSnodeAPI {
     this.randomSnodePool = [];
     this.swarmsPendingReplenish = {};
     this.refreshRandomPoolPromise = false;
+    this.versionPools = {};
 
     this.onionPaths = [];
     this.guardNodes = [];
@@ -254,6 +261,51 @@ class LokiSnodeAPI {
     ];
   }
 
+  // use nodes that support more than 1mb
+  async getRandomProxySnodeAddress() {
+    /* resolve random snode */
+    if (this.randomSnodePool.length === 0) {
+      // allow exceptions to pass through upwards
+      await this.refreshRandomPool();
+    }
+    if (this.randomSnodePool.length === 0) {
+      throw new window.textsecure.SeedNodeError('Invalid seed node response');
+    }
+    const goodVersions = Object.keys(this.versionPools).filter(version => {
+      return semver.gt(version, '2.0.1')
+    })
+    if (!goodVersions.length) {
+      return false;
+    }
+    console.log('goodVersions', goodVersions);
+    const goodVersion = goodVersions[Math.floor(Math.random() * goodVersions.length)];
+    console.log('goodVersion', goodVersion);
+    const pool = this.versionPools[goodVersion];
+    console.log('poolsize', pool.length);
+    return pool[
+      Math.floor(Math.random() * pool.length)
+    ];
+  }
+
+  async getVersion(node, count, total) {
+    try {
+      process.env.NODE_TLS_REJECT_UNAUTHORIZED = '0';
+      const result = await nodeFetch(`https://${node.ip}:${node.port}/get_stats/v1`, { agent: snodeHttpsAgent });
+      process.env.NODE_TLS_REJECT_UNAUTHORIZED = '1';
+      const data = await result.json();
+      console.log(`${count}/${total} ${node.ip}:${node.port}`, 'is on', data.version);
+      if (data.version) {
+        if (this.versionPools[data.version] === undefined) {
+          this.versionPools[data.version] = [ node ];
+        } else {
+          this.versionPools[data.version].push(node);
+        }
+      }
+    } catch(e) {
+      console.log('loki_snode:::getVersion - Error', e.code, e.message);
+    }
+  }
+
   async refreshRandomPool(seedNodes = [...window.seedNodeList]) {
     // if currently not in progress
     if (this.refreshRandomPoolPromise === false) {
@@ -295,6 +347,9 @@ class LokiSnodeAPI {
             snodes = response.result.service_node_states.filter(
               snode => snode.public_ip !== '0.0.0.0'
             );
+            // commit changes to be live
+            // we'll update the version (in case they upgrade) every cycle
+            this.versionPools = {};
             this.randomSnodePool = snodes.map(snode => ({
               ip: snode.public_ip,
               port: snode.storage_port,
@@ -312,7 +367,14 @@ class LokiSnodeAPI {
               clearTimeout(timeoutTimer);
               timeoutTimer = null;
             }
+            // start polling versions
             resolve();
+            let c = 0;
+            const t = this.randomSnodePool.length;
+            for(let node of this.randomSnodePool) {
+              c += 1;
+              await this.getVersion(node, c, t);
+            }
           } catch (e) {
             log.warn(
               'loki_snodes:::refreshRandomPoolPromise - error',

From 91b254d35528b96772ed7c0c76d50e1d46612738 Mon Sep 17 00:00:00 2001
From: Ryan Tharp <neuro@interx.net>
Date: Wed, 25 Mar 2020 00:20:25 -0700
Subject: [PATCH 03/15] versionMap reverse lookup, markRandomNodeUnreachable
 removes from versionPools now, lint

---
 js/modules/loki_snode_api.js | 67 +++++++++++++++++++++++++-----------
 1 file changed, 46 insertions(+), 21 deletions(-)

diff --git a/js/modules/loki_snode_api.js b/js/modules/loki_snode_api.js
index 5f47bab8e..1176dbad6 100644
--- a/js/modules/loki_snode_api.js
+++ b/js/modules/loki_snode_api.js
@@ -25,6 +25,7 @@ class LokiSnodeAPI {
     this.swarmsPendingReplenish = {};
     this.refreshRandomPoolPromise = false;
     this.versionPools = {};
+    this.versionMap = {};
 
     this.onionPaths = [];
     this.guardNodes = [];
@@ -37,6 +38,10 @@ class LokiSnodeAPI {
     return this.randomSnodePool;
   }
 
+  getRandomPoolLength() {
+    return this.randomSnodePool.length;
+  }
+
   async testGuardNode(snode) {
     log.info('Testing a candidate guard node ', snode);
 
@@ -271,38 +276,52 @@ class LokiSnodeAPI {
     if (this.randomSnodePool.length === 0) {
       throw new window.textsecure.SeedNodeError('Invalid seed node response');
     }
-    const goodVersions = Object.keys(this.versionPools).filter(version => {
-      return semver.gt(version, '2.0.1')
-    })
+    const goodVersions = Object.keys(this.versionPools).filter(version =>
+      semver.gt(version, '2.0.1')
+    );
     if (!goodVersions.length) {
       return false;
     }
-    console.log('goodVersions', goodVersions);
-    const goodVersion = goodVersions[Math.floor(Math.random() * goodVersions.length)];
-    console.log('goodVersion', goodVersion);
+    const goodVersion =
+      goodVersions[Math.floor(Math.random() * goodVersions.length)];
     const pool = this.versionPools[goodVersion];
-    console.log('poolsize', pool.length);
-    return pool[
-      Math.floor(Math.random() * pool.length)
-    ];
+    return pool[Math.floor(Math.random() * pool.length)];
   }
 
   async getVersion(node, count, total) {
     try {
       process.env.NODE_TLS_REJECT_UNAUTHORIZED = '0';
-      const result = await nodeFetch(`https://${node.ip}:${node.port}/get_stats/v1`, { agent: snodeHttpsAgent });
+      const result = await nodeFetch(
+        `https://${node.ip}:${node.port}/get_stats/v1`,
+        { agent: snodeHttpsAgent }
+      );
       process.env.NODE_TLS_REJECT_UNAUTHORIZED = '1';
       const data = await result.json();
-      console.log(`${count}/${total} ${node.ip}:${node.port}`, 'is on', data.version);
+      log.info(
+        `${count}/${total} ${node.ip}:${node.port}`,
+        'is on',
+        data.version
+      );
       if (data.version) {
         if (this.versionPools[data.version] === undefined) {
-          this.versionPools[data.version] = [ node ];
+          this.versionPools[data.version] = [node];
         } else {
           this.versionPools[data.version].push(node);
         }
+        // set up reverse mapping for removal lookup
+        this.versionMap[`${node.ip}:${node.port}`] = data.version;
       }
-    } catch(e) {
-      console.log('loki_snode:::getVersion - Error', e.code, e.message);
+    } catch (e) {
+      this.markRandomNodeUnreachable(node);
+      const randomNodesLeft = this.getRandomPoolLength();
+      log.warn(
+        'loki_snode:::getVersion - Error',
+        e.code,
+        e.message,
+        `removing ${node.ip}:${
+          node.port
+        } leaving ${randomNodesLeft} in the randomPool`
+      );
     }
   }
 
@@ -371,10 +390,10 @@ class LokiSnodeAPI {
             resolve();
             let c = 0;
             const t = this.randomSnodePool.length;
-            for(let node of this.randomSnodePool) {
+            this.randomSnodePool.forEach(async node => {
               c += 1;
               await this.getVersion(node, c, t);
-            }
+            });
           } catch (e) {
             log.warn(
               'loki_snodes:::refreshRandomPoolPromise - error',
@@ -465,16 +484,22 @@ class LokiSnodeAPI {
   }
 
   markRandomNodeUnreachable(snode) {
+    const snodeVersion = this.versionMap[`${snode.ip}:${snode.port}`];
+    if (this.versionPools[snodeVersion]) {
+      this.versionPools[snodeVersion] = _.without(
+        this.versionPools[snodeVersion],
+        _.find(this.versionPools[snodeVersion], {
+          ip: snode.ip,
+          port: snode.port,
+        })
+      );
+    }
     this.randomSnodePool = _.without(
       this.randomSnodePool,
       _.find(this.randomSnodePool, { ip: snode.ip, port: snode.port })
     );
   }
 
-  getRandomPoolLength() {
-    return this.randomSnodePool.length;
-  }
-
   async updateLastHash(snode, hash, expiresAt) {
     await window.Signal.Data.updateLastHash({ snode, hash, expiresAt });
   }

From cf5e186bcdd2d35a812678111bd9b45dccfc0ae1 Mon Sep 17 00:00:00 2001
From: Ryan Tharp <neuro@interx.net>
Date: Wed, 25 Mar 2020 01:39:02 -0700
Subject: [PATCH 04/15] change delay to 10s for initial retries, also remove
 space between time and units

---
 js/expire.js | 12 +++---------
 1 file changed, 3 insertions(+), 9 deletions(-)

diff --git a/js/expire.js b/js/expire.js
index c068921e5..a116cc14b 100644
--- a/js/expire.js
+++ b/js/expire.js
@@ -16,7 +16,7 @@
     LokiFileServerAPI.secureRpcPubKey
   );
 
-  let nextWaitSeconds = 1;
+  let nextWaitSeconds = 10;
   const checkForUpgrades = async () => {
     const result = await window.tokenlessFileServerAdnAPI.serverRequest(
       'loki/v1/version/client/desktop'
@@ -67,9 +67,7 @@
         return res(expiredVersion);
       }
       log.info(
-        'Delaying sending checks for',
-        nextWaitSeconds,
-        's, no version yet'
+        `Delaying sending checks for ${nextWaitSeconds}s, no version yet`
       );
       setTimeout(waitForVersion, nextWaitSeconds * 1000);
       return true;
@@ -85,11 +83,7 @@
   window.extension.expired = cb => {
     if (expiredVersion === null) {
       // just give it another second
-      log.info(
-        'Delaying expire banner determination for',
-        nextWaitSeconds,
-        's'
-      );
+      log.info(`Delaying expire banner determination for ${nextWaitSeconds}s`);
       setTimeout(() => {
         window.extension.expired(cb);
       }, nextWaitSeconds * 1000);

From 586aa877da175a8410ad57f8110fe07b248c2dea Mon Sep 17 00:00:00 2001
From: Ryan Tharp <neuro@interx.net>
Date: Wed, 25 Mar 2020 01:40:18 -0700
Subject: [PATCH 05/15] change delay to 10s retry

---
 js/modules/loki_app_dot_net_api.js | 3 ++-
 1 file changed, 2 insertions(+), 1 deletion(-)

diff --git a/js/modules/loki_app_dot_net_api.js b/js/modules/loki_app_dot_net_api.js
index 5b4db12b6..143d27d6b 100644
--- a/js/modules/loki_app_dot_net_api.js
+++ b/js/modules/loki_app_dot_net_api.js
@@ -49,8 +49,9 @@ const sendToProxy = async (
   // use nodes that support more than 1mb
   const randSnode = await lokiSnodeAPI.getRandomProxySnodeAddress();
   if (randSnode === false) {
+    log.warn('proxy random snode pool is not ready, retrying 10s', endpoint);
     // no nodes in the pool yet, give it some time and retry
-    await timeoutDelay(1000);
+    await timeoutDelay(10000);
     return sendToProxy(srvPubKey, endpoint, pFetchOptions, options);
   }
   const url = `https://${randSnode.ip}:${randSnode.port}/file_proxy`;

From c8b097c60e9359a1e219cd2e36c504551d5a944c Mon Sep 17 00:00:00 2001
From: Ryan Tharp <neuro@interx.net>
Date: Wed, 25 Mar 2020 02:32:57 -0700
Subject: [PATCH 06/15] clean up logging a bit

---
 js/modules/loki_rpc.js | 44 ++++++++++++++++--------------------------
 1 file changed, 17 insertions(+), 27 deletions(-)

diff --git a/js/modules/loki_rpc.js b/js/modules/loki_rpc.js
index 78f2414d9..98fb69390 100644
--- a/js/modules/loki_rpc.js
+++ b/js/modules/loki_rpc.js
@@ -136,33 +136,32 @@ const processOnionResponse = async (reqIdx, response, sharedKey, useAesGcm) => {
 
   // detect SNode is not ready (not in swarm; not done syncing)
   if (response.status === 503) {
-    log.warn('Got 503: snode not ready');
+    log.warn(`(${reqIdx}) [path] Got 503: snode not ready`);
 
     return BAD_PATH;
   }
 
   if (response.status === 504) {
-    log.warn('Got 504: Gateway timeout');
+    log.warn(`(${reqIdx}) [path] Got 504: Gateway timeout`);
     return BAD_PATH;
   }
 
   if (response.status === 404) {
     // Why would we get this error on testnet?
-    log.warn('Got 404: Gateway timeout');
+    log.warn(`(${reqIdx}) [path] Got 404: Gateway timeout`);
     return BAD_PATH;
   }
 
   if (response.status !== 200) {
     log.warn(
-      'lokiRpc sendToProxy fetch unhandled error code:',
-      response.status
+      `(${reqIdx}) [path] fetch unhandled error code: ${response.status}`
     );
     return false;
   }
 
   const ciphertext = await response.text();
   if (!ciphertext) {
-    log.warn('[path]: Target node return empty ciphertext');
+    log.warn(`(${reqIdx}) [path]: Target node return empty ciphertext`);
     return false;
   }
 
@@ -183,9 +182,9 @@ const processOnionResponse = async (reqIdx, response, sharedKey, useAesGcm) => {
     const textDecoder = new TextDecoder();
     plaintext = textDecoder.decode(plaintextBuffer);
   } catch (e) {
-    log.error(`(${reqIdx}) lokiRpc sendToProxy decode error`);
+    log.error(`(${reqIdx}) [path] decode error`);
     if (ciphertextBuffer) {
-      log.error('ciphertextBuffer', ciphertextBuffer);
+      log.error(`(${reqIdx}) [path] ciphertextBuffer`, ciphertextBuffer);
     }
     return false;
   }
@@ -198,22 +197,13 @@ const processOnionResponse = async (reqIdx, response, sharedKey, useAesGcm) => {
         const res = JSON.parse(jsonRes.body);
         return res;
       } catch (e) {
-        log.error(
-          `(${reqIdx}) lokiRpc sendToProxy parse error json: `,
-          jsonRes.body
-        );
+        log.error(`(${reqIdx}) [path] parse error json: `, jsonRes.body);
       }
       return false;
     };
     return jsonRes;
   } catch (e) {
-    log.error(
-      'lokiRpc sendToProxy parse error',
-      e.code,
-      e.message,
-      `json:`,
-      plaintext
-    );
+    log.error('[path] parse error', e.code, e.message, `json:`, plaintext);
     return false;
   }
 };
@@ -281,7 +271,7 @@ const sendToProxy = async (options = {}, targetNode, retryNumber = 0) => {
     lokiSnodeAPI.markRandomNodeUnreachable(randSnode);
     const randomPoolRemainingCount = lokiSnodeAPI.getRandomPoolLength();
     log.warn(
-      `lokiRpc sendToProxy`,
+      `lokiRpc:::sendToProxy - `,
       `snode ${randSnode.ip}:${randSnode.port} to ${targetNode.ip}:${
         targetNode.port
       }`,
@@ -306,7 +296,7 @@ const sendToProxy = async (options = {}, targetNode, retryNumber = 0) => {
     lokiSnodeAPI.markRandomNodeUnreachable(randSnode);
     const randomPoolRemainingCount = lokiSnodeAPI.getRandomPoolLength();
     log.warn(
-      `lokiRpc sendToProxy`,
+      `lokiRpc:::sendToProxy - `,
       `snode ${randSnode.ip}:${randSnode.port} to ${targetNode.ip}:${
         targetNode.port
       }`,
@@ -346,7 +336,7 @@ const sendToProxy = async (options = {}, targetNode, retryNumber = 0) => {
   if (response.status !== 200) {
     // let us know we need to create handlers for new unhandled codes
     log.warn(
-      'lokiRpc sendToProxy fetch non-200 statusCode',
+      'lokiRpc:::sendToProxy - fetch non-200 statusCode',
       response.status,
       `from snode ${randSnode.ip}:${randSnode.port} to ${targetNode.ip}:${
         targetNode.port
@@ -381,7 +371,7 @@ const sendToProxy = async (options = {}, targetNode, retryNumber = 0) => {
     plaintext = textDecoder.decode(plaintextBuffer);
   } catch (e) {
     log.error(
-      'lokiRpc sendToProxy decode error',
+      'lokiRpc:::sendToProxy - decode error',
       e.code,
       e.message,
       `from ${randSnode.ip}:${randSnode.port} to ${targetNode.ip}:${
@@ -403,7 +393,7 @@ const sendToProxy = async (options = {}, targetNode, retryNumber = 0) => {
         return JSON.parse(jsonRes.body);
       } catch (e) {
         log.error(
-          'lokiRpc sendToProxy parse error',
+          'lokiRpc:::sendToProxy - parse error',
           e.code,
           e.message,
           `from ${randSnode.ip}:${randSnode.port} json:`,
@@ -414,7 +404,7 @@ const sendToProxy = async (options = {}, targetNode, retryNumber = 0) => {
     };
     if (retryNumber) {
       log.info(
-        `lokiRpc sendToProxy request succeeded,`,
+        `lokiRpc:::sendToProxy - request succeeded,`,
         `snode ${randSnode.ip}:${randSnode.port} to ${targetNode.ip}:${
           targetNode.port
         }`,
@@ -424,7 +414,7 @@ const sendToProxy = async (options = {}, targetNode, retryNumber = 0) => {
     return jsonRes;
   } catch (e) {
     log.error(
-      'lokiRpc sendToProxy parse error',
+      'lokiRpc:::sendToProxy - parse error',
       e.code,
       e.message,
       `from ${randSnode.ip}:${randSnode.port} json:`,
@@ -515,7 +505,7 @@ const lokiFetch = async (url, options = {}, targetNode = null) => {
       fetchOptions.agent = snodeHttpsAgent;
       process.env.NODE_TLS_REJECT_UNAUTHORIZED = '0';
     } else {
-      log.info('lokiRpc http communication', url);
+      log.info('[path] http communication', url);
     }
     const response = await nodeFetch(url, fetchOptions);
     // restore TLS checking

From 40951f05793b19a33657389343ad0a9717882103 Mon Sep 17 00:00:00 2001
From: Ryan Tharp <neuro@interx.net>
Date: Wed, 25 Mar 2020 02:34:54 -0700
Subject: [PATCH 07/15] this.versionsRetrieved, handle ECONNREFUSED as bad
 otherwise retry in 1s, randomize list of snodes, only report status every 10%

---
 js/modules/loki_snode_api.js | 83 ++++++++++++++++++++++++++----------
 1 file changed, 61 insertions(+), 22 deletions(-)

diff --git a/js/modules/loki_snode_api.js b/js/modules/loki_snode_api.js
index 1176dbad6..ba2a9feb4 100644
--- a/js/modules/loki_snode_api.js
+++ b/js/modules/loki_snode_api.js
@@ -14,6 +14,8 @@ const snodeHttpsAgent = new https.Agent({
 const RANDOM_SNODES_TO_USE_FOR_PUBKEY_SWARM = 3;
 const SEED_NODE_RETRIES = 3;
 
+const timeoutDelay = ms => new Promise(resolve => setTimeout(resolve, ms));
+
 class LokiSnodeAPI {
   constructor({ serverUrl, localUrl }) {
     if (!is.string(serverUrl)) {
@@ -25,7 +27,8 @@ class LokiSnodeAPI {
     this.swarmsPendingReplenish = {};
     this.refreshRandomPoolPromise = false;
     this.versionPools = {};
-    this.versionMap = {};
+    this.versionMap = {}; // reverse version look up
+    this.versionsRetrieved = false; // to mark when it's done getting versions
 
     this.onionPaths = [];
     this.guardNodes = [];
@@ -214,7 +217,7 @@ class LokiSnodeAPI {
           log.warn(
             `could not find some guard nodes: ${this.guardNodes.length}/${
               edKeys.length
-            }`
+            } left`
           );
         }
       }
@@ -261,6 +264,7 @@ class LokiSnodeAPI {
     if (this.randomSnodePool.length === 0) {
       throw new window.textsecure.SeedNodeError('Invalid seed node response');
     }
+    // FIXME: _.sample?
     return this.randomSnodePool[
       Math.floor(Math.random() * this.randomSnodePool.length)
     ];
@@ -282,13 +286,15 @@ class LokiSnodeAPI {
     if (!goodVersions.length) {
       return false;
     }
+    // FIXME: _.sample?
     const goodVersion =
       goodVersions[Math.floor(Math.random() * goodVersions.length)];
     const pool = this.versionPools[goodVersion];
+    // FIXME: _.sample?
     return pool[Math.floor(Math.random() * pool.length)];
   }
 
-  async getVersion(node, count, total) {
+  async getVersion(node) {
     try {
       process.env.NODE_TLS_REJECT_UNAUTHORIZED = '0';
       const result = await nodeFetch(
@@ -297,11 +303,6 @@ class LokiSnodeAPI {
       );
       process.env.NODE_TLS_REJECT_UNAUTHORIZED = '1';
       const data = await result.json();
-      log.info(
-        `${count}/${total} ${node.ip}:${node.port}`,
-        'is on',
-        data.version
-      );
       if (data.version) {
         if (this.versionPools[data.version] === undefined) {
           this.versionPools[data.version] = [node];
@@ -312,16 +313,28 @@ class LokiSnodeAPI {
         this.versionMap[`${node.ip}:${node.port}`] = data.version;
       }
     } catch (e) {
-      this.markRandomNodeUnreachable(node);
-      const randomNodesLeft = this.getRandomPoolLength();
-      log.warn(
-        'loki_snode:::getVersion - Error',
-        e.code,
-        e.message,
-        `removing ${node.ip}:${
-          node.port
-        } leaving ${randomNodesLeft} in the randomPool`
-      );
+      // ECONNREFUSED likely means it's just offline...
+      if (e.code === 'ECONNREFUSED') {
+        this.markRandomNodeUnreachable(node);
+        const randomNodesLeft = this.getRandomPoolLength();
+        // clean up these error messages to be a little neater
+        log.warn(
+          `loki_snode:::getVersion - ${node.ip}:${
+            node.port
+          } is offline, removing, leaving ${randomNodesLeft} in the randomPool`
+        );
+      } else {
+        // mostly ECONNRESETs
+        // ENOTFOUND could mean no internet or hiccup
+        log.warn(
+          'loki_snode:::getVersion - Error',
+          e.code,
+          e.message,
+          `on ${node.ip}:${node.port} retrying in 1s`
+        );
+        await timeoutDelay(1000);
+        await this.getVersion(node);
+      }
     }
   }
 
@@ -366,9 +379,12 @@ class LokiSnodeAPI {
             snodes = response.result.service_node_states.filter(
               snode => snode.public_ip !== '0.0.0.0'
             );
+            // make sure order of the list is random, so we get version in a non-deterministic way
+            snodes = _.shuffle(snodes);
             // commit changes to be live
             // we'll update the version (in case they upgrade) every cycle
             this.versionPools = {};
+            this.versionsRetrieved = false;
             this.randomSnodePool = snodes.map(snode => ({
               ip: snode.public_ip,
               port: snode.storage_port,
@@ -389,11 +405,34 @@ class LokiSnodeAPI {
             // start polling versions
             resolve();
             let c = 0;
+            const verionStart = Date.now();
             const t = this.randomSnodePool.length;
-            this.randomSnodePool.forEach(async node => {
-              c += 1;
-              await this.getVersion(node, c, t);
-            });
+            const noticeEvery = parseInt(t / 10, 10);
+            const finalPromise = this.randomSnodePool.reduce(
+              async (p, node) => {
+                if (p) {
+                  await p;
+                  c += 1;
+                  if (c % noticeEvery === 0) {
+                    // give stats
+                    const diff = Date.now() - verionStart;
+                    log.info(
+                      `${c}/${t} pool version status update, has taken ${diff.toLocaleString()}ms`
+                    );
+                    Object.keys(this.versionPools).forEach(version => {
+                      const nodes = this.versionPools[version].length;
+                      log.info(
+                        `version ${version} has ${nodes.toLocaleString()} snodes`
+                      );
+                    });
+                  }
+                }
+                return this.getVersion(node);
+              }
+            );
+            await finalPromise;
+            log.info('Versions retrieved from network!');
+            this.versionsRetrieved = true;
           } catch (e) {
             log.warn(
               'loki_snodes:::refreshRandomPoolPromise - error',

From 8ceb47823f3b22857eff9e7ed47f8c8540c2f6a4 Mon Sep 17 00:00:00 2001
From: Ryan Tharp <neuro@interx.net>
Date: Wed, 25 Mar 2020 02:39:46 -0700
Subject: [PATCH 08/15] fix logging style

---
 js/modules/loki_rpc.js | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/js/modules/loki_rpc.js b/js/modules/loki_rpc.js
index 98fb69390..ae0eb05ed 100644
--- a/js/modules/loki_rpc.js
+++ b/js/modules/loki_rpc.js
@@ -505,7 +505,7 @@ const lokiFetch = async (url, options = {}, targetNode = null) => {
       fetchOptions.agent = snodeHttpsAgent;
       process.env.NODE_TLS_REJECT_UNAUTHORIZED = '0';
     } else {
-      log.info('[path] http communication', url);
+      log.info('lokirpc:::lokiFetch - http communication', url);
     }
     const response = await nodeFetch(url, fetchOptions);
     // restore TLS checking

From ae9bcd45c2f1b7cb3cd91998a72950ddb564e0d5 Mon Sep 17 00:00:00 2001
From: Ryan Tharp <neuro@interx.net>
Date: Thu, 26 Mar 2020 17:30:06 -0700
Subject: [PATCH 09/15] only be picky about file uploads

---
 js/modules/loki_app_dot_net_api.js | 24 +++++++++++++++---------
 1 file changed, 15 insertions(+), 9 deletions(-)

diff --git a/js/modules/loki_app_dot_net_api.js b/js/modules/loki_app_dot_net_api.js
index 143d27d6b..d31a54347 100644
--- a/js/modules/loki_app_dot_net_api.js
+++ b/js/modules/loki_app_dot_net_api.js
@@ -46,15 +46,6 @@ const sendToProxy = async (
     );
     return {};
   }
-  // use nodes that support more than 1mb
-  const randSnode = await lokiSnodeAPI.getRandomProxySnodeAddress();
-  if (randSnode === false) {
-    log.warn('proxy random snode pool is not ready, retrying 10s', endpoint);
-    // no nodes in the pool yet, give it some time and retry
-    await timeoutDelay(10000);
-    return sendToProxy(srvPubKey, endpoint, pFetchOptions, options);
-  }
-  const url = `https://${randSnode.ip}:${randSnode.port}/file_proxy`;
 
   const fetchOptions = pFetchOptions; // make lint happy
   // safety issue with file server, just safer to have this
@@ -70,6 +61,7 @@ const sendToProxy = async (
   };
 
   // from https://github.com/sindresorhus/is-stream/blob/master/index.js
+  let fileUpload = false;
   if (
     payloadObj.body &&
     typeof payloadObj.body === 'object' &&
@@ -83,8 +75,22 @@ const sendToProxy = async (
     payloadObj.body = {
       fileUpload: fData.toString('base64'),
     };
+    fileUpload = true;
   }
 
+  // use nodes that support more than 1mb
+  const randomFunc = fileUpload
+    ? 'getRandomProxySnodeAddress'
+    : 'getRandomSnodeAddress';
+  const randSnode = await lokiSnodeAPI[randomFunc]();
+  if (randSnode === false) {
+    log.warn('proxy random snode pool is not ready, retrying 10s', endpoint);
+    // no nodes in the pool yet, give it some time and retry
+    await timeoutDelay(10000);
+    return sendToProxy(srvPubKey, endpoint, pFetchOptions, options);
+  }
+  const url = `https://${randSnode.ip}:${randSnode.port}/file_proxy`;
+
   // convert our payload to binary buffer
   const payloadData = Buffer.from(
     dcodeIO.ByteBuffer.wrap(JSON.stringify(payloadObj)).toArrayBuffer()

From 055ba2aa66aea77928e6e209c941ac70b5dea958 Mon Sep 17 00:00:00 2001
From: Ryan Tharp <neuro@interx.net>
Date: Thu, 26 Mar 2020 17:31:00 -0700
Subject: [PATCH 10/15] fix bug with missing ciphertext in log msg, remove
 unneeded space from log messages

---
 js/modules/loki_rpc.js | 14 ++++++--------
 1 file changed, 6 insertions(+), 8 deletions(-)

diff --git a/js/modules/loki_rpc.js b/js/modules/loki_rpc.js
index ae0eb05ed..89d2ba615 100644
--- a/js/modules/loki_rpc.js
+++ b/js/modules/loki_rpc.js
@@ -270,8 +270,9 @@ const sendToProxy = async (options = {}, targetNode, retryNumber = 0) => {
     // we got a ton of randomPool nodes, let's just not worry about this one
     lokiSnodeAPI.markRandomNodeUnreachable(randSnode);
     const randomPoolRemainingCount = lokiSnodeAPI.getRandomPoolLength();
+    const ciphertext = await response.text();
     log.warn(
-      `lokiRpc:::sendToProxy - `,
+      `lokiRpc:::sendToProxy -`,
       `snode ${randSnode.ip}:${randSnode.port} to ${targetNode.ip}:${
         targetNode.port
       }`,
@@ -287,16 +288,13 @@ const sendToProxy = async (options = {}, targetNode, retryNumber = 0) => {
 
   // detect SNode is not ready (not in swarm; not done syncing)
   if (response.status === 503 || response.status === 500) {
-    const ciphertext = await response.text();
-    // we shouldn't do these,
-    // it's seems to be not the random node that's always bad
-    // but the target node
-
-    // we got a ton of randomPool nodes, let's just not worry about this one
+    // this doesn't mean the random node is bad, it could be the target node
+    // but we got a ton of randomPool nodes, let's just not worry about this one
     lokiSnodeAPI.markRandomNodeUnreachable(randSnode);
     const randomPoolRemainingCount = lokiSnodeAPI.getRandomPoolLength();
+    const ciphertext = await response.text();
     log.warn(
-      `lokiRpc:::sendToProxy - `,
+      `lokiRpc:::sendToProxy -`,
       `snode ${randSnode.ip}:${randSnode.port} to ${targetNode.ip}:${
         targetNode.port
       }`,

From 6fdde3294872fdeec01a84e590b473efb000c4fc Mon Sep 17 00:00:00 2001
From: Ryan Tharp <neuro@interx.net>
Date: Thu, 26 Mar 2020 17:35:55 -0700
Subject: [PATCH 11/15] convert reduce back to for...of loop per Maxim,
 markRandomNodeUnreachable() make handle edge removal cases and optimize snode
 lookup

---
 js/modules/loki_snode_api.js | 95 ++++++++++++++++++++++--------------
 1 file changed, 58 insertions(+), 37 deletions(-)

diff --git a/js/modules/loki_snode_api.js b/js/modules/loki_snode_api.js
index ba2a9feb4..945ba6591 100644
--- a/js/modules/loki_snode_api.js
+++ b/js/modules/loki_snode_api.js
@@ -314,8 +314,11 @@ class LokiSnodeAPI {
       }
     } catch (e) {
       // ECONNREFUSED likely means it's just offline...
+      // ECONNRESET seems to retry and fail as ECONNREFUSED (so likely a node going offline)
+      // ETIMEDOUT not sure what to do about these
+      // retry for now but maybe we should be marking bad...
       if (e.code === 'ECONNREFUSED') {
-        this.markRandomNodeUnreachable(node);
+        this.markRandomNodeUnreachable(node, { versionPoolFailure: true });
         const randomNodesLeft = this.getRandomPoolLength();
         // clean up these error messages to be a little neater
         log.warn(
@@ -408,29 +411,25 @@ class LokiSnodeAPI {
             const verionStart = Date.now();
             const t = this.randomSnodePool.length;
             const noticeEvery = parseInt(t / 10, 10);
-            const finalPromise = this.randomSnodePool.reduce(
-              async (p, node) => {
-                if (p) {
-                  await p;
-                  c += 1;
-                  if (c % noticeEvery === 0) {
-                    // give stats
-                    const diff = Date.now() - verionStart;
-                    log.info(
-                      `${c}/${t} pool version status update, has taken ${diff.toLocaleString()}ms`
-                    );
-                    Object.keys(this.versionPools).forEach(version => {
-                      const nodes = this.versionPools[version].length;
-                      log.info(
-                        `version ${version} has ${nodes.toLocaleString()} snodes`
-                      );
-                    });
-                  }
-                }
-                return this.getVersion(node);
+            // eslint-disable-next-line no-restricted-syntax
+            for (const node of this.randomSnodePool) {
+              c += 1;
+              // eslint-disable-next-line no-await-in-loop
+              await this.getVersion(node);
+              if (c % noticeEvery === 0) {
+                // give stats
+                const diff = Date.now() - verionStart;
+                log.info(
+                  `${c}/${t} pool version status update, has taken ${diff.toLocaleString()}ms`
+                );
+                Object.keys(this.versionPools).forEach(version => {
+                  const nodes = this.versionPools[version].length;
+                  log.info(
+                    `version ${version} has ${nodes.toLocaleString()} snodes`
+                  );
+                });
               }
-            );
-            await finalPromise;
+            }
             log.info('Versions retrieved from network!');
             this.versionsRetrieved = true;
           } catch (e) {
@@ -522,21 +521,43 @@ class LokiSnodeAPI {
     return filteredNodes;
   }
 
-  markRandomNodeUnreachable(snode) {
-    const snodeVersion = this.versionMap[`${snode.ip}:${snode.port}`];
-    if (this.versionPools[snodeVersion]) {
-      this.versionPools[snodeVersion] = _.without(
-        this.versionPools[snodeVersion],
-        _.find(this.versionPools[snodeVersion], {
-          ip: snode.ip,
-          port: snode.port,
-        })
-      );
+  markRandomNodeUnreachable(snode, options = {}) {
+    // avoid retries when we can't get the version because they're offline
+    if (!options.versionPoolFailure) {
+      const snodeVersion = this.versionMap[`${snode.ip}:${snode.port}`];
+      if (this.versionPools[snodeVersion]) {
+        this.versionPools[snodeVersion] = _.without(
+          this.versionPools[snodeVersion],
+          snode
+        );
+      } else {
+        if (snodeVersion) {
+          // reverse map (versionMap) is out of sync with versionPools
+          log.error(
+            'loki_snode:::markRandomNodeUnreachable - No snodes for version',
+            snodeVersion,
+            'retrying in 10s'
+          );
+        } else {
+          // we don't know our version yet
+          log.warn(
+            'loki_snode:::markRandomNodeUnreachable - No version for snode',
+            `${snode.ip}:${snode.port}`,
+            'retrying in 10s'
+          );
+        }
+        // make sure we don't retry past 15 mins (10s * 100 ~ 1000s)
+        if (options.retries < 100) {
+          setTimeout(() => {
+            this.markRandomNodeUnreachable(snode, {
+              ...options,
+              retries: options.retries + 1,
+            });
+          }, 10000);
+        }
+      }
     }
-    this.randomSnodePool = _.without(
-      this.randomSnodePool,
-      _.find(this.randomSnodePool, { ip: snode.ip, port: snode.port })
-    );
+    this.randomSnodePool = _.without(this.randomSnodePool, snode);
   }
 
   async updateLastHash(snode, hash, expiresAt) {

From a7981b1645a75f9e00938f92c02420cbcf531177 Mon Sep 17 00:00:00 2001
From: Ryan Tharp <neuro@interx.net>
Date: Thu, 26 Mar 2020 17:58:35 -0700
Subject: [PATCH 12/15] add some notes

---
 js/modules/loki_snode_api.js | 5 +++++
 1 file changed, 5 insertions(+)

diff --git a/js/modules/loki_snode_api.js b/js/modules/loki_snode_api.js
index 945ba6591..b013fca41 100644
--- a/js/modules/loki_snode_api.js
+++ b/js/modules/loki_snode_api.js
@@ -294,6 +294,8 @@ class LokiSnodeAPI {
     return pool[Math.floor(Math.random() * pool.length)];
   }
 
+  // WARNING: this leaks our IP to all snodes but with no other identifying information
+  // except that a client started up or ran out of random pool snodes
   async getVersion(node) {
     try {
       process.env.NODE_TLS_REJECT_UNAUTHORIZED = '0';
@@ -407,6 +409,8 @@ class LokiSnodeAPI {
             }
             // start polling versions
             resolve();
+            // now get version for all snodes
+            // also acts an early online test/purge of bad nodes
             let c = 0;
             const verionStart = Date.now();
             const t = this.randomSnodePool.length;
@@ -540,6 +544,7 @@ class LokiSnodeAPI {
           );
         } else {
           // we don't know our version yet
+          // and if we're offline, we'll likely not get it until it restarts if it does...
           log.warn(
             'loki_snode:::markRandomNodeUnreachable - No version for snode',
             `${snode.ip}:${snode.port}`,

From 0336b09fd4275a67961de642c1e7fa59991d54a1 Mon Sep 17 00:00:00 2001
From: Ryan Tharp <neuro@interx.net>
Date: Thu, 26 Mar 2020 18:00:06 -0700
Subject: [PATCH 13/15] tweak expire delay

---
 js/expire.js | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/js/expire.js b/js/expire.js
index a116cc14b..228508caf 100644
--- a/js/expire.js
+++ b/js/expire.js
@@ -16,7 +16,7 @@
     LokiFileServerAPI.secureRpcPubKey
   );
 
-  let nextWaitSeconds = 10;
+  let nextWaitSeconds = 5;
   const checkForUpgrades = async () => {
     const result = await window.tokenlessFileServerAdnAPI.serverRequest(
       'loki/v1/version/client/desktop'

From dcfae3bedca80c12a2e40b0abc162b52cdf28a64 Mon Sep 17 00:00:00 2001
From: Ryan Tharp <neuro@interx.net>
Date: Thu, 26 Mar 2020 18:02:50 -0700
Subject: [PATCH 14/15] improve user UX since we shouldn't have to wait on
 startup

---
 js/modules/loki_app_dot_net_api.js | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/js/modules/loki_app_dot_net_api.js b/js/modules/loki_app_dot_net_api.js
index d31a54347..ef56f8c1b 100644
--- a/js/modules/loki_app_dot_net_api.js
+++ b/js/modules/loki_app_dot_net_api.js
@@ -86,7 +86,7 @@ const sendToProxy = async (
   if (randSnode === false) {
     log.warn('proxy random snode pool is not ready, retrying 10s', endpoint);
     // no nodes in the pool yet, give it some time and retry
-    await timeoutDelay(10000);
+    await timeoutDelay(1000);
     return sendToProxy(srvPubKey, endpoint, pFetchOptions, options);
   }
   const url = `https://${randSnode.ip}:${randSnode.port}/file_proxy`;

From 75ef07048acfeb5036486fa80d716ac0acb78522 Mon Sep 17 00:00:00 2001
From: Ryan Tharp <neuro@interx.net>
Date: Thu, 26 Mar 2020 18:10:17 -0700
Subject: [PATCH 15/15] make sure retries is set

---
 js/modules/loki_snode_api.js | 5 +++--
 1 file changed, 3 insertions(+), 2 deletions(-)

diff --git a/js/modules/loki_snode_api.js b/js/modules/loki_snode_api.js
index b013fca41..9642d64e0 100644
--- a/js/modules/loki_snode_api.js
+++ b/js/modules/loki_snode_api.js
@@ -552,11 +552,12 @@ class LokiSnodeAPI {
           );
         }
         // make sure we don't retry past 15 mins (10s * 100 ~ 1000s)
-        if (options.retries < 100) {
+        const retries = options.retries || 0;
+        if (retries < 100) {
           setTimeout(() => {
             this.markRandomNodeUnreachable(snode, {
               ...options,
-              retries: options.retries + 1,
+              retries: retries + 1,
             });
           }, 10000);
         }