diff --git a/js/modules/loki_rpc.js b/js/modules/loki_rpc.js index 5ee2794bd..136adb9c5 100644 --- a/js/modules/loki_rpc.js +++ b/js/modules/loki_rpc.js @@ -195,7 +195,8 @@ const sendToProxy = async (options = {}, targetNode, retryNumber = 0) => { let snodePool = await lokiSnodeAPI.getRandomSnodePool(); if (snodePool.length < 2) { - log.error( + // this is semi-normal to happen + log.info( 'lokiRpc::sendToProxy - Not enough service nodes for a proxy request, only have:', snodePool.length, 'snode, attempting refresh' @@ -277,7 +278,33 @@ const sendToProxy = async (options = {}, targetNode, retryNumber = 0) => { return sendToProxy(options, targetNode, retryNumber + 1); } + // relay is fine but destination is not good + if (response.status === 504) { + + const pRetryNumber = retryNumber + 1; + if (pRetryNumber > 3) { + log.warn( + `lokiRpc:::sendToProxy - snode ${randSnode.ip}:${randSnode.port}`, + `can not relay to target node ${targetNode.ip}:${targetNode.port}`, + `after 3 retries` + ); + if (options.ourPubKey) { + lokiSnodeAPI.unreachableNode(options.ourPubKey, targetNode); + } else { + console.trace('no ourPubKey in call') + } + return false; + } + // we don't have to wait here + // because we're not marking the random snode bad + + // grab a fresh random one + return sendToProxy(options, targetNode, pRetryNumber); + } + // detect SNode is not ready (not in swarm; not done syncing) + // 503 can be proxy target or destination in pre 2.0.3 + // 2.0.3 and after means target if (response.status === 503 || response.status === 500) { // 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 @@ -390,7 +417,7 @@ const sendToProxy = async (options = {}, targetNode, retryNumber = 0) => { return JSON.parse(jsonRes.body); } catch (e) { log.error( - 'lokiRpc:::sendToProxy - parse error', + 'lokiRpc:::sendToProxy - (inner) parse error', e.code, e.message, `from ${randSnode.ip}:${randSnode.port} json:`, @@ -400,7 +427,7 @@ const sendToProxy = async (options = {}, targetNode, retryNumber = 0) => { return false; }; if (retryNumber) { - log.info( + log.debug( `lokiRpc:::sendToProxy - request succeeded,`, `snode ${randSnode.ip}:${randSnode.port} to ${targetNode.ip}:${ targetNode.port @@ -411,7 +438,7 @@ const sendToProxy = async (options = {}, targetNode, retryNumber = 0) => { return jsonRes; } catch (e) { log.error( - 'lokiRpc:::sendToProxy - parse error', + 'lokiRpc:::sendToProxy - (outer) parse error', e.code, e.message, `from ${randSnode.ip}:${randSnode.port} json:`, @@ -475,12 +502,19 @@ const lokiFetch = async (url, options = {}, targetNode = null) => { const result = await sendToProxy(fetchOptions, targetNode); if (result === false) { // should we retry? - log.warn(`lokiRpc:::lokiFetch - sendToProxy returned false`); + + // even though we can't be sure our caller is going to log or handle the failure + // we do know that sendToProxy should be logging + // so I don't think we need or want a log item here... + // log.warn(`lokiRpc:::lokiFetch - sendToProxy failed`); + // one case is: // snodePool didn't have enough // even after a refresh // likely a network disconnect? - // but not all cases... + // another is: + // failure to send to target node after 3 retries + // what else? /* log.warn( 'lokiRpc:::lokiFetch - useSnodeProxy failure, could not refresh randomPool, offline?' @@ -498,7 +532,7 @@ const lokiFetch = async (url, options = {}, targetNode = null) => { fetchOptions.agent = snodeHttpsAgent; process.env.NODE_TLS_REJECT_UNAUTHORIZED = '0'; } else { - log.info('lokirpc:::lokiFetch - http communication', url); + log.debug('lokirpc:::lokiFetch - http communication', url); } const response = await nodeFetch(url, fetchOptions); // restore TLS checking