Amplitude-Android icon indicating copy to clipboard operation
Amplitude-Android copied to clipboard

Events logged in close succession sometimes get logged in the wrong order.

Open makaroffandrey opened this issue 7 years ago • 8 comments

Setup

Android, implementation 'com.amplitude:android-sdk:2.15.0' in build.gradle Two activities:FirstActivity and SecondActivity. FirstActivity has a button that opens SecondActivity

Thee events:

  • FirstActivity opened logged in FirstActivity.onCreate()
  • FirstActivity button pressed logged in OnClickListener.OnClick() that is set to the button in FirstActivity
  • SecondActivity opened logged in SecondActivity.onCreate()

What is wrong

On https://analytics.amplitude.com SecondActivity opened sometimes appears before FirstActivity button pressed. Example: screen shot 2017-11-02 at 09 31 38 This complicates funnel analysis on funnels that depend on the order of events.

Setting enableLogging(true).setLogLevel(Log.VERBOSE) shows these events being logged in correct order

11-02 02:51:31.253 5722-5741/com.makaroffandrey.amplitudetest D/com.amplitude.api.AmplitudeClient: Logged event to Amplitude: FirstActivity opened
11-02 02:51:35.477 5722-5741/com.makaroffandrey.amplitudetest D/com.amplitude.api.AmplitudeClient: Logged event to Amplitude: FirstActivity button pressed
11-02 02:51:35.541 5722-5741/com.makaroffandrey.amplitudetest D/com.amplitude.api.AmplitudeClient: Logged event to Amplitude: SecondActivity opened

On the website these events have "client_event_time" and "event_id" values indicate correct order. "_time" and "event_time" values indicate incorrect order.

Increasing the time between events by logging in onResume() instead of onCreate() does not help.

I will publish an MCVE shortly.

Edit

MCVE is here

makaroffandrey avatar Nov 02 '17 07:11 makaroffandrey

@makaroffandrey are you saying that the raw _time values are incorrect, or that the events are in the wrong order on the user activity timeline? If multiple events have the same timestamp, they could show up out of order on the timeline (due to the sorting algorithm for the timeline). In terms of ordered funnels, as long as the _time value is correct, then the order will be correct in the funnel as the funnel algorithm does a strict ordering based on that _time value.

djih avatar Nov 02 '17 23:11 djih

@djih I am saying that both _time values are incorrect and the events appear in the wrong order. The difference in time between events is about 100ms, so it cannot be a sorting issue. What I also see is inconsistency between _time and client_event_time. I used the debugger to check which time gets passed to

public void logEvent(String, JSONObject eventProperties, JSONObject groups, long timestamp, boolean outOfSession)

as a timestamp, and noticed that this time is displayed as client_event_time on the website. As I understand, I cannot influence _time directly, but could you tell me how do you determine _time? If I knew how it works, I could probably figure out a workaround on my side.

makaroffandrey avatar Nov 03 '17 06:11 makaroffandrey

@makaroffandrey apologies for the slow response. Here is a help article explaining how we compute the final event _time which is used for sorting: https://amplitude.zendesk.com/hc/en-us/articles/229313067-User-Activity#event-time. Basically its a combination of the time reported by the device client event time, and the time recorded by our servers at the time of receiving the request server upload time. We make some adjustments in case the device's local time is inaccurate somehow.

djih avatar Nov 07 '17 22:11 djih

@djih Hey Im facing a similar issue, Please check the client event time in the below images

ScreenShot-1 Screenshot 2019-06-26 at 5 34 23 PM

Screenshot-2 Screenshot 2019-06-26 at 5 36 28 PM

in the above screenshots you can see that start session is happening first and view tasks is happening later as per client event time but the order in which events are shown is not correct. Can u guys come up with a fix for this ?

MouleshS avatar Jun 26 '19 12:06 MouleshS

Have the same issue.. there are any workarounds?

NaikSoftware avatar Jul 30 '19 14:07 NaikSoftware

We have same problem. Any news here?

itruf avatar Aug 05 '19 15:08 itruf

Facing with same issue. Is anyone have workarounds?

Null45 avatar Aug 05 '19 15:08 Null45

@NaikSoftware @itruf @Null45 if you guys have CSMs you can reach out to them. There's a feature flag we can enable for you that will strictly order events based on event id instead of timestamp.

djih avatar Aug 05 '19 21:08 djih