Websocket events arriving out of order?

  • 1
  • Problem
  • Updated 2 years ago
  • In Progress
  • (Edited)
Archived and Closed

This conversation is no longer open for comments or replies and is no longer visible to community members.

I'm using the real-time events API (websockets) to monitor our cars. Unfortunately, a lot of the location_update events come completely out of order. They also randomly list a different timezone! Look at the log pasted below. Is this expected behavior? 

Here's my log, in the order I received the events (note the timestamps out of order and the randomly changing timezones):
{u'created_at': u'2016-11-04T00:22:31.000Z' u'America/New_York'
{u'created_at': u'2016-11-04T00:20:51.000Z' u'America/New_York'
{u'created_at': u'2016-11-04T00:23:31.000Z' u'America/New_York'
{u'created_at': u'2016-11-04T00:19:11.000Z' u'America/New_York'
{u'created_at': u'2016-11-04T00:22:31.000Z' u'America/New_York'
{u'created_at': u'2016-11-04T00:25:11.000Z' u'America/New_York'
{u'created_at': u'2016-11-04T00:24:31.000Z' u'America/New_York'
{u'created_at': u'2016-11-04T00:24:51.000Z' u'America/New_York'
{u'created_at': u'2016-11-04T00:27:11.000Z' u'America/New_York'
{u'created_at': u'2016-11-04T00:19:51.000Z' u'America/New_York'
{u'created_at': u'2016-11-04T00:18:49.000Z' u'America/Chicago'
{u'created_at': u'2016-11-04T00:18:49.000Z' u'America/Chicago'
{u'created_at': u'2016-11-04T00:23:31.000Z' u'America/New_York'
{u'created_at': u'2016-11-04T00:24:51.000Z' u'America/New_York'
{u'created_at': u'2016-11-04T00:24:31.000Z' u'America/New_York'
{u'created_at': u'2016-11-04T00:25:31.000Z' u'America/New_York'
{u'created_at': u'2016-11-04T00:19:51.000Z' u'America/New_York'
{u'created_at': u'2016-11-04T00:21:31.000Z' u'America/New_York'
{u'created_at': u'2016-11-04T00:28:31.000Z' u'America/New_York'
{u'created_at': u'2016-11-04T00:27:51.000Z' u'America/New_York'
{u'created_at': u'2016-11-04T00:26:51.000Z' u'America/New_York'
{u'created_at': u'2016-11-04T00:25:31.000Z' u'America/New_York'
{u'created_at': u'2016-11-04T00:26:11.000Z' u'America/New_York'
{u'created_at': u'2016-11-04T00:22:31.000Z' u'America/New_York'
{u'created_at': u'2016-11-04T00:18:49.000Z' u'America/Chicago'
{u'created_at': u'2016-11-04T00:24:31.000Z' u'America/New_York'
{u'created_at': u'2016-11-04T00:24:51.000Z' u'America/New_York'
{u'created_at': u'2016-11-04T00:27:31.000Z' u'America/New_York'
{u'created_at': u'2016-11-04T00:24:31.000Z' u'America/New_York'
{u'created_at': u'2016-11-04T00:26:31.000Z' u'America/New_York'
{u'created_at': u'2016-11-04T00:27:31.000Z' u'America/New_York'
{u'created_at': u'2016-11-04T00:27:51.000Z' u'America/New_York'
{u'created_at': u'2016-11-04T00:28:51.000Z' u'America/New_York'
{u'created_at': u'2016-11-04T00:28:11.000Z' u'America/New_York'
{u'created_at': u'2016-11-04T00:25:31.000Z' u'America/New_York'
{u'created_at': u'2016-11-04T00:29:21.000Z' u'America/Chicago'
{u'created_at': u'2016-11-04T00:29:11.000Z' u'America/New_York'
{u'created_at': u'2016-11-04T00:26:11.000Z' u'America/New_York'
{u'created_at': u'2016-11-04T00:25:31.000Z' u'America/New_York'
{u'created_at': u'2016-11-04T00:19:11.000Z' u'America/New_York'
{u'created_at': u'2016-11-04T00:22:31.000Z' u'America/New_York'
{u'created_at': u'2016-11-04T00:26:31.000Z' u'America/New_York'
{u'created_at': u'2016-11-04T00:26:51.000Z' u'America/New_York'
{u'created_at': u'2016-11-04T00:25:31.000Z' u'America/New_York'
{u'created_at': u'2016-11-04T00:26:31.000Z' u'America/New_York'
{u'created_at': u'2016-11-04T00:24:31.000Z' u'America/New_York'
{u'created_at': u'2016-11-04T00:28:11.000Z' u'America/New_York'
{u'created_at': u'2016-11-04T00:26:11.000Z' u'America/New_York'
{u'created_at': u'2016-11-04T00:26:31.000Z' u'America/New_York'
{u'created_at': u'2016-11-04T00:26:11.000Z' u'America/New_York'
{u'created_at': u'2016-11-04T00:29:11.000Z' u'America/New_York'
{u'created_at': u'2016-11-04T00:29:21.000Z' u'America/Chicago'
{u'created_at': u'2016-11-04T00:28:51.000Z' u'America/New_York'
{u'created_at': u'2016-11-04T00:26:31.000Z' u'America/New_York'
{u'created_at': u'2016-11-04T00:28:11.000Z' u'America/New_York'
{u'created_at': u'2016-11-04T00:26:11.000Z' u'America/New_York'
Photo of Matt Farley

Matt Farley

  • 1,506 Points 1k badge 2x thumb

Posted 2 years ago

  • 1
Photo of Adam Altman

Adam Altman, Alum

  • 3,712 Points 3k badge 2x thumb
Hi Matt!

This is within the realm of promised behavior, but is a bit unexpected. Officially there is no guarantee of chronological ordering as events are processed through a distributed system and sequential events can be sent to different workers. That said, the severity of this disorder is pretty unusual IF you're showing all one event type, e.g. location updated. If it is mixing in all events, that could explain it as each type has different stages of processing to go through.

The timezones thing is simple to explain. Each event tries to get a GPS point to associate. If it can get one it converts the time to the timezone of that location. If no GPS point was available, we send the event anyway and state times with a default timezone.

Cheers,
Adam
Photo of Matt Farley

Matt Farley

  • 1,506 Points 1k badge 2x thumb
Hi Adam, thanks for the explanation! Unfortunately, everything in that log is the same event type: location:updated, on the same car, on a single trip -- so like you said, it is pretty severe.

This makes it difficult to write apps that do things like show the car moving on a live map -- the car bounces all over the map, makes my wife's driving look like a space ship :) 
Photo of Adam Altman

Adam Altman, Alum

  • 3,712 Points 3k badge 2x thumb
I understand - yep that's annoying. I'll point a few folks at it, see what we can do. No promises though. I would expect that it will be better on another day though, even without any patches.
(Edited)
Photo of Matt Farley

Matt Farley

  • 1,506 Points 1k badge 2x thumb
Okay, thanks Adam! Much appreciated!
Photo of Adam Altman

Adam Altman, Alum

  • 3,712 Points 3k badge 2x thumb
Good news. Spoke to engineers. There are some infrastructure upgrades underway that should make this significantly better in about a week. From there, "the correct" thing should be coming towards the end of the year.
Photo of Matt Farley

Matt Farley

  • 1,506 Points 1k badge 2x thumb
HI Adam -- any updates on ETA for "the correct" thing?
Photo of Adam Altman

Adam Altman, Alum

  • 3,712 Points 3k badge 2x thumb
I'll check with folks...standby.
Photo of Adam Altman

Adam Altman, Alum

  • 3,712 Points 3k badge 2x thumb
Hi Matt - "most" of the work to improve event delivery was done in November but there's a piece that got pushed out to January unfortunately. We can dive a little deeper and see if we can aid your account specifically in the meantime. There are two matt farleys in our DB: are you the gmail or the vanity domain one?
Photo of Matt Farley

Matt Farley

  • 1,506 Points 1k badge 2x thumb
Thanks Adam! Vanity domain one.
Photo of Amy

Amy

  • 68,970 Points 50k badge 2x thumb
Thanks, Adam!
Photo of Matt Farley

Matt Farley

  • 1,506 Points 1k badge 2x thumb
Awesome! Thanks again!
Photo of xrak en

xrak en

  • 1,196 Points 1k badge 2x thumb
Just got around to checking my updates from yesterday and I'm also seeing the rather large discrepancies in messages arriving out of sequence for the location update messages. The messages are sometimes 15 minutes out of order (i.e. after receiving a message for say 10:50:25 the next one might be 10:40:35). From observing the sequence of messages it almost seems like there are three sources of messages where each source is reporting in sequence but when the 3 streams are intermixed into a single stream of websocket messages they seem to be out of sequence.
Looking forward to Adam's short-term and long term fixes.
Photo of Matt Farley

Matt Farley

  • 1,506 Points 1k badge 2x thumb
Yeah.. I'm still getting random lag too, but instead of 10-30 minutes late, it's more commonly 3-10 minutes late (still enough to be annoying). This even happens outside of rush hour (e.g. this morning, Saturday at 8am).

This conversation is no longer open for comments or replies.