Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Session Id didn't rotate after 23 hours #227

Open
ioannisj opened this issue Nov 1, 2024 · 15 comments
Open

Session Id didn't rotate after 23 hours #227

ioannisj opened this issue Nov 1, 2024 · 15 comments
Labels
bug Something isn't working Session Replay

Comments

@ioannisj
Copy link
Contributor

ioannisj commented Nov 1, 2024

Description

A user reported that a session recording lasted for around 24 hours. After taking a look at the recording, we do indeed capture a few snapshots at the very end of the recording (timestamps look correct), right before the session is rotated.

This is weird cause we clear the session_id on every capture here and rotate it after about 30 mins when the app is foregrounded here.

Also, session id/window id is managed only in memory, so it's very unlikely that the OS suspended the app but didn't terminate it for 23 hours.

From: https://posthoghelp.zendesk.com/agent/tickets/19974

@ioannisj ioannisj added bug Something isn't working Session Replay labels Nov 1, 2024
@ioannisj
Copy link
Contributor Author

ioannisj commented Nov 1, 2024

@marandaneto any ideas on what could be going on here? Especially last part of my comment above - leads me to think that these could be events in the queue with the wrong timestamp somehow

@marandaneto
Copy link
Member

@marandaneto any ideas on what could be going on here? Especially last part of my comment above - leads me to think that these could be events in the queue with the wrong timestamp somehow

I think the problem is that the resetSessionIfExpired isn't considering the timestamp of the snapshot event which is only generated when PostHogEvent instance is created.
In this case, if its possible to know that the session has expired and the session has more than 24h, the event snapshot event should be even dropped and not captured without a session_id.
For example, JS has the function checkAndGetSessionAndWindowId and other ones that do a lot of checking, I don't think we need to do everything the same but we are probably missing something.
Strange is that the snapshot had a session_id right, and that I don't know how its possible without further investigation.

@marandaneto
Copy link
Member

Another point is that we capture a "$snapshot" event in a background thread (eg PostHogReplayIntegration.dispatchQueue), but the event timestamp is only created when its executed, I think the event.timestamp should be passed to the capture method along with the "$snapshot" event so we compare the time that the event actually happened instead of when the event was captured (when the queue wasn't paused anymore or something).

@marandaneto
Copy link
Member

#228
I think we should pass timestamp here as described here

@marandaneto
Copy link
Member

https://github.com/PostHog/posthog-js/blob/a6655acf6910ecea144758b89358311797604941/src/sessionid.ts#L15
this is also not enforced on the SDK yet
https://posthog.com/docs/data/sessions

A new session is started by default when either there's no activity for 30 minutes or the session has reached the maximum session duration of 24 hours

@ioannisj
Copy link
Contributor Author

ioannisj commented Nov 6, 2024

#227 (comment) I think this is an improvement for sure, but I don't think it's the cause of the issue.

Whenever the event was captured, it was captured along with the correct session_id that we only assign in capture() for $snapshot events - right before adding it to the queue. So the causes for this that I can see could be:

  • resetSessionIfExpired is not called cause isInBackground is false for some reason, even though the app is firing from a background state
  • Host app is calling setSessionId(_ sessionId: String) manually which overrides whatever rotation we are doing

@ioannisj
Copy link
Contributor Author

ioannisj commented Nov 8, 2024

Finally making some headway here! After watching a bunch of recordings, I think I have an idea of what could be going on. I noticed quite a few recordings had this pattern where Application Opened and Application Backgrounded events would appear within 2-3 seconds of each other. Initially, I didn’t think too much of it, but it turns out that every time we detect an app open, we're updating sessionLastTimestamp, which unintentionally extends the session time when the app really in the background.

We’re currently observing didBecomeActiveNotification, which (if I’ve got this right – I’ll confirm soon) also fires when the app becomes active in the background, like during a background fetch or a push notification. I'll test this with a local project to get a clearer view of exactly how these notifications are triggered. Apple docs mention that "An app is active when it is receiving events." which makes me feel this may be the case.

Here are a few ideas on how to handle this:

  • Refine how we detect actual background and foreground events based on the above and local tests I'll be running. We may need to add a small delay before handling an app open event.
  • Instead of manually tracking isInBackground within capture(), we could poll UIApplication.shared.applicationState to check the app’s real-time state. It might require some thread-hopping if called from a background thread (since UIApplication can only be accessed on the main thread), which is a bit of a downside.
  • Since there could be delays with using the NotificationCenter, we could instead use KVO on UIApplication.shared.applicationState to monitor for any state changes.

@marandaneto
Copy link
Member

but it turns out that every time we detect an app open, we're updating sessionLastTimestamp

we only do that for handleAppDidEnterBackground and not handleAppDidBecomeActive.

@marandaneto
Copy link
Member

which (if I’ve got this right – I’ll confirm soon) also fires when the app becomes active in the background, like during a background fetch or a push notification. I'll test this with a local project to get a clearer view of exactly how these notifications are triggered. Apple docs mention that "An app is active when it is receiving events." which makes me feel this may be the case.

Curious about that, I recall testing this in the past but happy to be wrong here.

@marandaneto
Copy link
Member

Since there could be delays with using the NotificationCenter, we could instead use KVO on UIApplication.shared.applicationState to monitor for any state changes.

That is a good point, applicationState has 3 states that differ from them, but let's be sure that the current notifications don't work the way I assumed to work.

@ioannisj
Copy link
Contributor Author

but it turns out that every time we detect an app open, we're updating sessionLastTimestamp

we only do that for handleAppDidEnterBackground and not handleAppDidBecomeActive.

Yeah, true actually, but if this is called when already in background, it will unintentionally extend the session time right?

@marandaneto
Copy link
Member

I assume the app is in the foreground if handleAppDidBecomeActive is received, I assume the app is in the background if handleAppDidEnterBackground, so I'd assume it's doing the right thing.
I don't see how handleAppDidBecomeActive would be received if the app is in the background, if that's the case, it is somehow an Apple OS bug that we have to go around and that would cause an issue on our end yes, that's why I asked to confirmed here.

@ioannisj
Copy link
Contributor Author

I tried testing my assumption locally but without any success. Notifications appear to work as expected, at least on the latest iOS in both the simulator and on a real device. My testing involved simulating a background fetch on both platforms, but I couldn’t test remote push notifications since they require a developer account setup. So I'm not sure how remote would behave in this case.

It seems like events are picking up an old $session_id that should have been cleared or rotated. So my focus still remains on either sessionLastTimestamp or isInBackground, as these are the main flags involved in session clearing. But at this point, I’m running out of ideas for what could be causing the problem tbh

@ioannisj
Copy link
Contributor Author

@marandaneto any more insights from the other user you mentioned having this problem?

@marandaneto
Copy link
Member

@marandaneto any more insights from the other user you mentioned having this problem?

discussed offline, and shared some links, but not more than that.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working Session Replay
Projects
None yet
Development

No branches or pull requests

2 participants