altangent / ccxws

WebSocket client for 38 cryptocurrency exchanges
MIT License
617 stars 186 forks source link

Bug L3 orderbook kucoin #203

Closed WoutervDijk closed 4 years ago

WoutervDijk commented 4 years ago

L3 orderbook gets out of sync really fast with Kucoin

@bmancini55 I have tried your L3 prototype OB and I have also built one myself, but both of them lose quite a lot of information it seems. I think it gets out of sync at least around every minute (so the sequenceId gets out of sync). To recreate the bug, just run your code and you should have an "out of sync, expected ${ob.sequenceId + 1}, got ${update.sequenceId}" error fast. Here is the exact code: const ccxws = require("ccxws"); const KucoinOrderBook = require("ccxws/src/orderbooks/KucoinOrderBook"); let market = {id: "BTC-USDT", base: "BTC", quote: "USDT"}; let updates = []; let ob; const client = new ccxws.Kucoin(); client.subscribeLevel3Updates(market); client.on("l3snapshot", snapshot => { ob = new KucoinOrderBook(snapshot, updates); }); client.on("l3update", update => { // enqueue updates until snapshot arrives if (!ob) { updates.push(update); return; } // validate the sequence and exit if we are out of sync if (ob.sequenceId + 1 !== update.sequenceId) { console.log(out of sync, expected ${ob.sequenceId + 1}, got ${update.sequenceId}); process.exit(1); } // apply update ob.update(update); });

The only thing I found about it as of right now, was someone who used python : https://github.com/Kucoin/kucoin-api-docs/issues/44#issuecomment-477105864

EDIT: Running on Node v14.7 on Windows 10

Really random guess, could be a fault in WS package and this could be the fix? https://github.com/websockets/ws/commit/e1349c047d7f1c120ca606364e35d5c4c627c599 Tried it myself didn't work unfortunately

bmancini55 commented 4 years ago

@WoutervDijk thanks for the update!

I've had mixed results with the duration before it goes out of sync. I checked to see if there was a correlation with garbage collection and didn't see anything glaringly obvious.

Its probably unlikely that its dropping packets on the socket level and is most likely an implementation problem of the order book or client.

The client is my bigger concern. To debug this I would connect to the update stream directly without running it through the order book and capture before and after a failure to see what's going on. It could be an ordering thing.

I can take a look this weekend hopefully. If you get a chance to capture any logs it would be awesome. Unfortunately I'm out of commission for a bit after nuking my laptop with a glass of water 😐

WoutervDijk commented 4 years ago

Thanks for the response @bmancini55 . I am running some tests right now, I'll keep you updated. EDIT first update: I ran this code of yours:

const ccxws = require("ccxws");
const KucoinOrderBook = require("ccxws/src/orderbooks/KucoinOrderBook");
let market = {id: "BTC-USDT", base: "BTC", quote: "USDT"};
let updates = [];
let ob;
const client = new ccxws.Kucoin();
client.subscribeLevel3Updates(market);
client.on("l3snapshot", snapshot => {
    ob = new KucoinOrderBook(snapshot, updates);
});
client.on("l3update", update => {
    // enqueue updates until snapshot arrives
    if (!ob) {
        updates.push(update);
        return;
    }
    // validate the sequence and exit if we are out of sync
    if (ob.sequenceId + 1 !== update.sequenceId) {
        console.log(`out of sync, expected ${ob.sequenceId + 1}, got ${update.sequenceId}`);
        //process.exit(1);
    }
    // apply update
    ob.update(update);
});

It ran quite long without out of sync errors and then a lot of them in a short time (within a minute) out of sync, expected 1594880712887, got 1594880712889 out of sync, expected 1594880712890, got 1594880712892 out of sync, expected 1594880717048, got 1594880717050 out of sync, expected 1594880720700, got 1594880720701 It is interesting to note that the missed (e.g. ....712887 above) packages never hit this function again. And there are often (not always) missing two packages at the same time

WoutervDijk commented 4 years ago

Good news! I have made some progress. I ran the following code in kucoin-client.js. I replaced _onMessage(raw) with:

    let replaced = raw.replace(/:(\d+\.{0,1}\d+)(,|\})/g, ':"$1"$2');
    try {
      let msgs = JSON.parse(replaced);
      if (msgs.type !== "welcome" && msgs.type !== "ack" && msgs.type !== "pong") {
        if (Number(msgs.data.sequence) !== this.superOldSeq + 1)
          console.log("Sequence is here alrady out of data, expected ", this.superOldSeq + 1, "got", msgs.data.sequence)
        this.superOldSeq = Number(msgs.data.sequence);
      } else if(msgs.type === "ack")
        console.log("ack receive", msgs.id)
      if (Array.isArray(msgs)) {
        for (let msg of msgs) {
          this._processMessage(msg);
        }
      } else {
        this._processMessage(msgs);
      }
    } catch (ex) {
      this._onError(ex);
    }
  }

Note this is bad code, but it is for debugging anyway. This new code doesn't log an out of sync error, while I did receive the out of sync in the order book implementation (the code above).

WoutervDijk commented 4 years ago

God damn, I am now really close to the solution I replaced _onMessage now with the following:

  _onMessage(raw) {
    let replaced = raw.replace(/:(\d+\.{0,1}\d+)(,|\})/g, ':"$1"$2');
    try {
      let msgs = JSON.parse(replaced);
      if (msgs.type !== "welcome" && msgs.type !== "ack" && msgs.type !== "pong") {
        if (Number(msgs.data.sequence) !== this.superOldSeq + 1)
          console.log("Sequence is here alrady out of data, expected ", this.superOldSeq + 1, "got", msgs.data.sequence)
        this.superOldSeq = Number(msgs.data.sequence);
        this.datas.push(msgs);
        setTimeout(() => this.datas.shift(), 1000);
      } else if(msgs.type === "ack")
        console.log("ack receive", msgs.id)
      else if(msgs.type === "welcome")
        this.datas = [];
      if (Array.isArray(msgs)) {
        for (let msg of msgs) {
          this._processMessage(msg);
        }
      } else {
        this._processMessage(msgs);
      }
    } catch (ex) {
      this._onError(ex);
    }
  }

This way I could store the data and see which data points were lost. It seems that the program does something wrong for subject "update". These are stored in my datas object, but in the orderbook implementation it says it would be out of sync!

WoutervDijk commented 4 years ago

Found the error in _processL3UpdateUpdate(msg). That first line should be let {symbol, sequence, orderId, size, ts} = msg => let {symbol, sequence, orderId, size, ts} = msg.data Could you fix it asap and release it please?

bmancini55 commented 4 years ago

Ah that'll do it, thanks for digging into it! It figures, the one event that doesn't have code coverage has a simple but major bug in it haha. I'll get a fix and release out shortly.

bmancini55 commented 4 years ago

Released in https://github.com/altangent/ccxws/releases/tag/v0.37.2. Also added a few minor fixes to the L3 order book.

WoutervDijk commented 4 years ago

Nice work thanks @bmancini55