From 0e67e2a0b7cdd73170e9d535fa2af302cf06de91 Mon Sep 17 00:00:00 2001 From: William Grant Date: Thu, 28 Sep 2023 11:42:56 +1000 Subject: [PATCH] feat: improved expiry retry and error handing nested pRetry Abort errors can break our retry logic so we need to catch them --- ts/session/apis/snode_api/expireRequest.ts | 113 +++++++----------- .../apis/snode_api/getExpiriesRequest.ts | 2 +- ts/util/expiringMessages.ts | 28 ++--- 3 files changed, 59 insertions(+), 84 deletions(-) diff --git a/ts/session/apis/snode_api/expireRequest.ts b/ts/session/apis/snode_api/expireRequest.ts index 59e1e4354..0c2faf220 100644 --- a/ts/session/apis/snode_api/expireRequest.ts +++ b/ts/session/apis/snode_api/expireRequest.ts @@ -134,7 +134,7 @@ async function processExpireRequestResponse( async function expireOnNodes( targetNode: Snode, expireRequest: UpdateExpiryOnNodeSubRequest -): Promise { +): Promise { try { const result = await doSnodeBatchRequest( [expireRequest], @@ -145,12 +145,11 @@ async function expireOnNodes( ); if (!result || result.length !== 1) { - window?.log?.warn( - `WIP: [expireOnNodes] There was an issue with the results. sessionRpc ${targetNode.ip}:${ + throw Error( + `There was an issue with the results. sessionRpc ${targetNode.ip}:${ targetNode.port } expireRequest ${JSON.stringify(expireRequest)}` ); - return null; } // TODOLATER make sure that this code still works once disappearing messages is merged @@ -158,55 +157,51 @@ async function expireOnNodes( const firstResult = result[0]; if (firstResult.code !== 200) { - window?.log?.warn(`WIP: [expireOnNodes] result is not 200 but ${firstResult.code}`); - return null; + throw Error(`result is not 200 but ${firstResult.code}`); } - try { - const bodyFirstResult = firstResult.body; - const expirationResults = await processExpireRequestResponse( - expireRequest.params.pubkey, - targetNode, - bodyFirstResult.swarm as ExpireMessagesResultsContent, - expireRequest.params.messages - ); - const firstExpirationResult = Object.entries(expirationResults).at(0); - if (!firstExpirationResult) { - window?.log?.warn( - 'WIP: [expireOnNodes] failed to parse "swarm" result. firstExpirationResult is null' - ); - throw new Error('firstExpirationResult is null'); - } + const bodyFirstResult = firstResult.body; + const expirationResults = await processExpireRequestResponse( + expireRequest.params.pubkey, + targetNode, + bodyFirstResult.swarm as ExpireMessagesResultsContent, + expireRequest.params.messages + ); + const firstExpirationResult = Object.entries(expirationResults).at(0); + if (!firstExpirationResult) { + throw new Error('firstExpirationResult is null'); + } - const messageHash = firstExpirationResult[0]; - const expiry = firstExpirationResult[1].expiry; + const messageHash = firstExpirationResult[0]; + const expiry = firstExpirationResult[1].expiry; - if (!expiry || !messageHash) { - throw new Error( - `Something is wrong with the firstExpirationResult: ${JSON.stringify( - JSON.stringify(firstExpirationResult) - )}` - ); - } + if (!expiry || !messageHash) { + throw new Error( + `Something is wrong with the firstExpirationResult: ${JSON.stringify( + JSON.stringify(firstExpirationResult) + )}` + ); + } - // window.log.debug( - // `WIP: [expireOnNodes] Success!\nHere are the results from one of the snodes.\nmessageHash: ${messageHash} \nexpiry: ${expiry} \nexpires at: ${new Date( - // expiry - // ).toUTCString()}\nnow: ${new Date(GetNetworkTime.getNowWithNetworkOffset()).toUTCString()}` - // ); + // window.log.debug( + // `WIP: [expireOnNodes] Success!\nHere are the results from one of the snodes.\nmessageHash: ${messageHash} \nexpiry: ${expiry} \nexpires at: ${new Date( + // expiry + // ).toUTCString()}\nnow: ${new Date(GetNetworkTime.getNowWithNetworkOffset()).toUTCString()}` + // ); - return expiry; - } catch (e) { - window?.log?.warn('WIP: [expireOnNodes] Failed to parse "swarm" result: ', e); - } - return null; - } catch (e) { + return expiry; + } catch (err) { window?.log?.warn( - 'WIP: [expireOnNodes] - send error:', - e, + 'WIP: [expireOnNodes]', + err.message || err, `destination ${targetNode.ip}:${targetNode.port}` ); - throw e; + // NOTE batch requests have their own retry logic which includes abort errors that will break our retry logic so we need to catch them and throw regular errors + if (err instanceof pRetry.AbortError) { + throw Error(err.message); + } + + throw err; } } @@ -299,38 +294,19 @@ export async function expireMessageOnSnode( let snode: Snode | undefined; - await pRetry( - async () => { - const swarm = await getSwarmFor(ourPubKey); - snode = sample(swarm); - if (!snode) { - throw new EmptySwarmError(ourPubKey, 'Ran out of swarm nodes to query'); - } - }, - { - retries: 3, - factor: 2, - minTimeout: SeedNodeAPI.getMinTimeout(), - onFailedAttempt: e => { - window?.log?.warn( - `WIP: [expireMessageOnSnode] get snode attempt #${e.attemptNumber} failed. ${e.retriesLeft} retries left... Error: ${e.message}` - ); - }, - } - ); - try { const expireRequestParams = await buildExpireRequest(props); if (!expireRequestParams) { throw new Error(`Failed to build expire request ${JSON.stringify(props)}`); } - let newTTL = null; await pRetry( async () => { + const swarm = await getSwarmFor(ourPubKey); + snode = sample(swarm); if (!snode) { - throw new Error(`No snode found.\n${JSON.stringify(props)}`); + throw new EmptySwarmError(ourPubKey, 'Ran out of swarm nodes to query'); } newTTL = await expireOnNodes(snode, expireRequestParams); }, @@ -350,9 +326,8 @@ export async function expireMessageOnSnode( } catch (e) { const snodeStr = snode ? `${snode.ip}:${snode.port}` : 'null'; window?.log?.warn( - `WIP: [expireMessageOnSnode] ${e.code ? `${e.code} ` : ''}${ - e.message - } by ${ourPubKey} for ${messageHash} via snode:${snodeStr}` + `WIP: [expireMessageOnSnode] ${e.code ? `${e.code} ` : ''}${e.message || + e} by ${ourPubKey} for ${messageHash} via snode:${snodeStr}` ); throw e; } diff --git a/ts/session/apis/snode_api/getExpiriesRequest.ts b/ts/session/apis/snode_api/getExpiriesRequest.ts index 1429b5343..337f65c17 100644 --- a/ts/session/apis/snode_api/getExpiriesRequest.ts +++ b/ts/session/apis/snode_api/getExpiriesRequest.ts @@ -244,7 +244,7 @@ export async function getExpiriesFromSnode( minTimeout: SeedNodeAPI.getMinTimeout(), onFailedAttempt: e => { window?.log?.warn( - `WIP: [getExpiriesFromSnode] expire message on snode attempt #${e.attemptNumber} failed. ${e.retriesLeft} retries left... Error: ${e.message}` + `WIP: [getExpiriesFromSnode] get expiries from snode attempt #${e.attemptNumber} failed. ${e.retriesLeft} retries left... Error: ${e.message}` ); }, } diff --git a/ts/util/expiringMessages.ts b/ts/util/expiringMessages.ts index 6204277d7..50823c65c 100644 --- a/ts/util/expiringMessages.ts +++ b/ts/util/expiringMessages.ts @@ -668,25 +668,25 @@ export async function updateMessageExpiryOnSwarm( expires_at: newTTL, }); - // window.log.debug( - // `WIP: [updateMessageExpiryOnSwarm] messageHash ${messageHash} has a new TTL of ${newTTL} which expires at ${new Date( - // newTTL - // ).toUTCString()}` - // ); + window.log.debug( + `WIP: [updateMessageExpiryOnSwarm] messageHash ${messageHash} has a new TTL of ${newTTL} which expires at ${new Date( + newTTL + ).toUTCString()}` + ); if (shouldCommit) { await message.commit(); } } else { - // window.log.warn( - // `WIP: [updateMessageExpiryOnSwarm]\nmessageHash ${messageHash} has no new TTL.${ - // expiresAt - // ? `\nKeeping the old one ${expiresAt}which expires at ${new Date( - // expiresAt - // ).toUTCString()}` - // : '' - // }` - // ); + window.log.warn( + `WIP: [updateMessageExpiryOnSwarm]\nmessageHash ${messageHash} has no new TTL.${ + expiresAt + ? `\nKeeping the old one ${expiresAt}which expires at ${new Date( + expiresAt + ).toUTCString()}` + : '' + }` + ); } return message;