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

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

Open
makaroffandrey opened this issue Nov 2, 2017 · 8 comments

Comments

@makaroffandrey
Copy link

makaroffandrey commented Nov 2, 2017

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 pushed a commit to makaroffandrey/Amplitude_issue_152_MCVE that referenced this issue Nov 2, 2017
@djih
Copy link
Member

djih commented Nov 2, 2017

@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.

@makaroffandrey
Copy link
Author

@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.

@djih
Copy link
Member

djih commented Nov 7, 2017

@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.

@MouleshS
Copy link

MouleshS commented Jun 26, 2019

@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 ?

@NaikSoftware
Copy link

Have the same issue.. there are any workarounds?

@itruf
Copy link

itruf commented Aug 5, 2019

We have same problem. Any news here?

@Null45
Copy link

Null45 commented Aug 5, 2019

Facing with same issue. Is anyone have workarounds?

@djih
Copy link
Member

djih commented Aug 5, 2019

@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.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

6 participants