PostHog / posthog-js-lite

Reimplementation of posthog-js to be as light and modular as possible.
https://posthog.com/docs/libraries
MIT License
63 stars 31 forks source link

Errors using posthog.shutdownAsync() #210

Closed rushil23 closed 6 months ago

rushil23 commented 6 months ago

Bug description

Our project is setup in a serverless manner using AWS lambdas, and we've already set our flushAt to 1 and flushInterval to 0 as recommended by Posthog. At the end of the lambda lifecycle, we're calling shutdownAsync which takes around ~10 seconds to run and console logs an error message:

Error while shutting down PostHog Error [PostHogFetchHttpError]: HTTP error while fetching PostHog: 400
|  +9885ms     at PostHogFetchHttpError (/Users/rushilnagarsheth/hypercard/hyper-repo/node_modules/posthog-core/src/index.ts:31:5)
|  +9885ms     at PostHog2.<anonymous> (/Users/rushilnagarsheth/hypercard/hyper-repo/node_modules/posthog-core/src/index.ts:558:17)
|  +9885ms     at step (/Users/rushilnagarsheth/hypercard/hyper-repo/node_modules/node_modules/tslib/tslib.es6.js:102:23)
|  +9885ms     at Object.next (/Users/rushilnagarsheth/hypercard/hyper-repo/node_modules/node_modules/tslib/tslib.es6.js:83:53)
|  +9885ms     at fulfilled (/Users/rushilnagarsheth/hypercard/hyper-repo/node_modules/node_modules/tslib/tslib.es6.js:73:58)
|  +9885ms     at process.processTicksAndRejections (node:internal/process/task_queues:95:5) {

Related sub-libraries

benjackwhite commented 6 months ago

What version of posthog-node are you using?

marandaneto commented 6 months ago

@rushil23 would you mind trying the latest version? https://github.com/PostHog/posthog-js-lite/blob/main/posthog-node/CHANGELOG.md#400---2024-03-18 shutdownAsync method was removed and a few improvements were made to the new method as well (shutdown), maybe the issue was solved altogether,.

rushil23 commented 6 months ago

@benjackwhite @marandaneto I am on latest 4.0.0 version. Still getting the following error:

 Error while shutting down PostHog PostHogFetchHttpError: HTTP error while fetching PostHog: 400
|  +11252ms     at retriable (/Users/rushilnagarsheth/hypercard/hyper-repo/node_modules/posthog-core/src/index.ts:649:17)
|  +11252ms     at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
|  +11252ms     at retriable (/Users/rushilnagarsheth/hypercard/hyper-repo/node_modules/posthog-core/src/utils.ts:27:19)
|  +11252ms     at PostHog.fetchWithRetry (/Users/rushilnagarsheth/hypercard/hyper-repo/node_modules/posthog-core/src/index.ts:632:12)
|  +11252ms     at PostHog._flush (/Users/rushilnagarsheth/hypercard/hyper-repo/node_modules/posthog-core/src/index.ts:602:7) {
|  +11252ms   response: Response {
|  +11252ms     [Symbol(realm)]: null,
|  +11252ms     [Symbol(state)]: {
|  +11252ms       aborted: false,
|  +11252ms       rangeRequested: false,
|  +11252ms       timingAllowPassed: true,
|  +11252ms       requestIncludesCredentials: true,
|  +11252ms       type: 'default',
|  +11252ms       status: 400,
|  +11252ms       timingInfo: [Object],
|  +11252ms       cacheState: '',
|  +11252ms       statusText: 'Bad Request',
|  +11252ms       headersList: [HeadersList],
|  +11252ms       urlList: [Array],
|  +11252ms       body: [Object]
|  +11252ms     },
|  +11252ms     [Symbol(headers)]: HeadersList {
|  +11252ms       cookies: null,
|  +11252ms       [Symbol(headers map)]: [Map],
|  +11252ms       [Symbol(headers map sorted)]: null
|  +11252ms     }
|  +11252ms   }
|  +11252ms }
marandaneto commented 6 months ago

@rushil23 Can you share your SDK init code snippet? Are you running self-hosted or PostHog EU/US?

rushil23 commented 6 months ago

@marandaneto -> not self hosted its probably PostHog US since we're based in the US

Library:

posthog-node 4.0.0

Library initialization:

const loadPosthog = () => {
const config = getDefaultLibraryConfig();

if (!posthog) {
posthog = new PostHog(config.posthogToken, {
/**
Necessary to guarantee delivery of events,
since we don't have a dedicated instance and have
lambdas running individual requests in separate containers */
flushAt: 1,
flushInterval: 0,
});
}
return posthog;
};

What was called:

export const cleanup = async () => {
const posthog = loadPosthog();
await posthog.shutdown();
};

Network request

https://webhook.site/#!/view/655fc38b-215d-4278-85ef-f8ac22da94f2/be723027-15d8-41b2-8abc-879cbd6f8f74/1 Screenshot 2024-03-21 at 5.36.20 PM.png

What was expected to happen:

Shutdown and flush all pending events.

What actually happened:

Error while shutting down PostHog PostHogFetchHttpError: HTTP error while fetching PostHog: 400 | +11252ms at retriable (/Users/rushilnagarsheth/hypercard/hyper-repo/node_modules/posthog-core/src/index.ts:649:17) | +11252ms at process.processTicksAndRejections (node:internal/process/task_queues:95:5) | +11252ms at retriable (/Users/rushilnagarsheth/hypercard/hyper-repo/node_modules/posthog-core/src/utils.ts:27:19) | +11252ms at PostHog.fetchWithRetry (/Users/rushilnagarsheth/hypercard/hyper-repo/node_modules/posthog-core/src/index.ts:632:12) | +11252ms at PostHog._flush (/Users/rushilnagarsheth/hypercard/hyper-repo/node_modules/posthog-core/src/index.ts:602:7) { | +11252ms response: Response { | +11252ms [Symbol(realm)]: null, | +11252ms [Symbol(state)]: { | +11252ms aborted: false, | +11252ms rangeRequested: false, | +11252ms timingAllowPassed: true, | +11252ms requestIncludesCredentials: true, | +11252ms type: 'default', | +11252ms status: 400, | +11252ms timingInfo: [Object], | +11252ms cacheState: '', | +11252ms statusText: 'Bad Request', | +11252ms headersList: [HeadersList], | +11252ms urlList: [Array], | +11252ms body: [Object] | +11252ms }, | +11252ms [Symbol(headers)]: HeadersList { | +11252ms cookies: null, | +11252ms [Symbol(headers map)]: [Map], | +11252ms [Symbol(headers map sorted)]: null | +11252ms } | +11252ms } | +11252ms }

benjackwhite commented 6 months ago

Am I right in understanding that you have the toke no-local-environment-for-posthog. If so that would explain the 400 at least as its pretty much the only thing that our capture endpoint will reject - an invalid token.

As for the 10 second time out I can investigate if that is perhaps an unaccounted for issue where we should be aggressively dropping that attempt and exiting out.

rushil23 commented 6 months ago

@benjackwhite : no that token is only used locally. we have a phc_C0C... token in development and another token in production as well. We're still getting a ton of errors from the posthog library. Would it be more helpful to get on a sync call for 10-15 minutes @benjackwhite ?

rushil23 commented 6 months ago

@benjackwhite : looks like we were passing undefined as a string distinct ID. Changed that to always be a random ID and it works now.