New order lag on socket

[dj2ball]

I'm wondering if anyone else is seeing this issue - I am gathering all incoming order data and building an offline order book. One thing I've noticed is that in some cases, an order comes in and it is already traded. And I'm not talking 1-5 seconds of lag, I mean, the etherscan timestamp for the successful trade is anything up to a minute(!) before the order is even passed to me via the socket connection. I'm just wondering what might be causing this, as I was under the impression that there was no caching/delay in receiving orders via the socket??

Any ideas?

[TonyRehley]

The same. I had hope that in new socket api there will be no cache. But no... So sometimes API returns first trade and after minutes related order. The order added via etherdelta UI are aslo showed with long (minutes) delay. @zackcoburn can you explain this delays? I know that servers can be slow, but we see that this delayed orders are traded before display (etherscan txt timestamp). It is decentralized (community) way to exchange?

[zackcoburn]

The initial data is still cached (60 seconds), but the updates are not cached. They're just grouped and streamed to everyone every 5 seconds. I'll look into the delays.

[TonyRehley]

Thanks @zackcoburn for answer. It will be nice solution. I will also check on more orders if it works in this way and maby give you some clues. If it was my mistake - sorry very much.

[rince83]

I am having the same issue. I am comparing the "updated" timestamps in the onOrder events to the time when I am actually receiving the updated orders and the time difference is often way higher than 5 seconds. Also some orders are already filled when I receive them so it seems not everyone gets every order at the same time?

[dj2ball]

This is exactly the kind of behaviour I'm describing. It seems similar to the old cached api when certain clients were on a xx seconds delay behind each other...

[dj2ball]

Did you ever find something on this Zack? Noticing it again over the last few days: orders come through for the first time, after trying to trade them I get a transaction fail say 10-12s later and yet when I check etherscan logs on the winning trade, it's often 40-50s before the socket even emitted the order.

I've run timeit in python to check there is no code delaying before the trade happens my end but between the on.order and the trade we're talking fractions of a second - nothing like the time above....

[ghost]

@dj2ball I have been noticing the same for a while now. Were you able to sort out the issue? Are you still experiencing the same delays in the trade execution?

[rkul]

The same for me:

[2018-02-09T23:19:19.343Z]
Order recieved: 2018-02-09T23:19:19.343Z
Order updated:  2018-02-09T23:18:54.707Z
Lag: 24.636 sec
https://etherdelta.com/#0x12b306fa98f4cbb8d4457fdff3a0a0a56f07ccdf-ETH
[2018-02-09T23:19:19.343Z] { id: '523804bfd7433a27360c740b142edcb11ac3e49250be3862e613f2a518b86e44_buy',
  amount: '582010000000000',
  price: '1614.5',
  tokenGet: '0x12b306fa98f4cbb8d4457fdff3a0a0a56f07ccdf',
  amountGet: '582010000000000',
  tokenGive: '0x0000000000000000000000000000000000000000',
  amountGive: '939655145000000000',
  expires: '5071642',
  nonce: '4292389528',
  v: 28,
  r: '0x41e0066e2de9cf193f7e4ece54e1129fa40bb48cbb41eb7e353754cece9ec0f6',
  s: '0x1d27ddeb524ed4227693a0721f890906a064cae501f8f54031404644c815bf9c',
  user: '0x48C4b6e1350ef4446131fe49bE912B552AC9c3D4',
  updated: '2018-02-09T23:18:54.707Z',
  availableVolume: '582010000000000',
  ethAvailableVolume: '0.00058201',
  availableVolumeBase: '939655145000000000',
  ethAvailableVolumeBase: '0.939655145',
  amountFilled: null }

I wrote simple monitoring script, which compares order update timestamp on each orders socket event:

[2018-02-09T22:42:20.951Z] Orders: 35/29
Jitter for buys min/avg/max = 87/144/197 sec
Jitter for sells min/avg/max = 92/140/184 sec
[2018-02-09T22:43:10.593Z] Orders: 35/22
Jitter for buys min/avg/max = 48/81/135 sec
Jitter for sells min/avg/max = 50/98/136 sec
[2018-02-09T22:43:29.775Z] Orders: 17/24
Jitter for buys min/avg/max = 19/43/67 sec
Jitter for sells min/avg/max = 19/46/68 sec
[2018-02-09T22:44:08.829Z] Orders: 6/4
Jitter for buys min/avg/max = 39/44/54 sec
Jitter for sells min/avg/max = 39/49/58 sec
[2018-02-09T22:44:20.323Z] Orders: 19/12
Jitter for buys min/avg/max = 24/36/47 sec
Jitter for sells min/avg/max = 14/29/44 sec

The code itself:

function lag(order) {
  let receivedDate = new Date().toISOString();
  let lag = (Date.parse(receivedDate) - Date.parse(order.updated))/1000
  return lag
}

function jitter(orders) {
  if (orders.length === 0) {
    return "min/avg/max = 0/0/0 sec"
  } else {
    let ordersLag = orders.map(o => parseFloat(lag(o)))
    minLag = Math.min(...ordersLag).toFixed(0)
    maxLag = Math.max(...ordersLag).toFixed(0)
    avgLag = (ordersLag.reduce((x,y) => x+y)/ordersLag.length).toFixed(0)
    return `min/avg/max = ${minLag}/${avgLag}/${maxLag} sec`
  }
}
service.socket.on('orders', function(newOrders) {
  console.log([
    `Jitter for buys ${jitter(newOrders.buys)}`,
    `Jitter for sells ${jitter(newOrders.sells.)}`,
  ].join('\n'))
}

@zackcoburn could you explain this lag?