stoqey / ib

Interactive Brokers TWS/IB Gateway API client library for Node.js (TS)
https://stoqey.github.io/ib-doc/
MIT License
189 stars 45 forks source link

Unprocessed Data #203

Open electic opened 4 months ago

electic commented 4 months ago

Hi everyone,

Getting this error: Error: Decoding error on OPEN_ORDER: unprocessed data left on queue (["","","","",null]).

How can I debug this?

BusinessDuck commented 4 months ago

Same for me.

Order in paper mode:

          orderType: ibOrderType.MKT,
          orderId: IBTransport.getReqId(),
          totalQuantity: pendingOrder.lots,
          action,
          tif: TimeInForce.IOC,
          transmit: true,

Fix via: https://github.com/stoqey/ib/pull/208

rylorin commented 3 months ago

Hello, Thanks for reporting. Cloud you please provide some information about the order? I was unable to reproduce this issue. Ideally add a test case to ./src/test/unit/api/order to help improving the reliably of the API. Thanks

paaax commented 2 months ago

I am also getting the error on version 1.3.19 in the following code snippet:

createOrder(req: any) {
    const options = req.body.options;

    // Preparing the contract based on request options
    let contract: Contract;
    if (options.secId) {
      // If secType is FIGI, use this specific contract definition
      contract = {
        secIdType: "FIGI",
        secId: options.secId,
        exchange: options.exchange,
      };
    } else {
      // Default contract definition for other secTypes
      contract = {
        symbol: options.symbol,
        exchange: options.exchange,
        currency: options.currency,
        secType: this.getSecType(req),
      };
    }

    // Handling specific contract attributes based on secType
    if (contract.secType === "STK" && options.primaryExch) {
      contract.primaryExch = options.primaryExch;
    }

    // Futures
    if (contract.secType === "FUT" && options.lastTradeDateOrContractMonth) {
      contract.lastTradeDateOrContractMonth =
        options.lastTradeDateOrContractMonth;
    }
    if (contract.secType === "FUT" && options.localSymbol) {
      contract.localSymbol = options.localSymbol;
    }
    if (contract.secType === "FUT" && options.multiplier) {
      contract.multiplier = options.multiplier;
    }

    // Single order
    const singleOrder: Order = {
      orderId: this.nextOrderId++,
      action:
        options.orderAction === "BUY" ? OrderAction.BUY : OrderAction.SELL,
      orderType: this.getOrderType(req),
      totalQuantity: options.quantity,
      lmtPrice: options.orderType === "LMT" ? options.lmtPrice : undefined,
      auxPrice: options.orderType.startsWith("STP")
        ? options.auxPrice
        : undefined,
      account: this.account,
      transmit: true,
      tif: options.tif,
    };

    // Placing the single order
    this.ib.placeOrder(singleOrder.orderId!, contract, singleOrder);
    winston.log("info", `Order placed with ID: ${singleOrder.orderId}`);
  }

When sending this:

  {
    "bracketOrder": false,
    "options": {
        "orderAction": "BUY",
        "symbol": "SPY",
        "exchange": "SMART",
        "lmtPrice": 1,
        "takeProfitLimitPrice": 1.2,
        "stopLossPrice": 0.9,
        "currency": "USD",
        "quantity": 1.0,
        "secType": "STK",
        "tif": "GTC",
        "orderType": "LMT"
    }
}
rylorin commented 2 months ago

Thanks. Could you please provide the values of singleOrder and contract when calling this.ib.placeOrder(singleOrder.orderId!, contract, singleOrder);? Don't forget to hide you account number.

paaax commented 2 months ago

Thank you for answering. It looks like the order id is set correctly and increases with incoming signals. The order is also being placed in TWS, but the error remains.

Here is my complete log (I changed the account number):

{"level":"info","message":"Listening to requests on 443"} {"level":"info","message":"Connecting to database..."} {"level":"info","message":"Connection to database established."} Broker connected Next valid order ID: 519 {"level":"info","message":"Signal received."} {"level":"info","message":"Placing order AAPL"} {"level":"info","message":"Contract Data: {\"symbol\":\"AAPL\",\"exchange\":\"SMART\",\"currency\":\"USD\",\"secType\":\"STK\"}"} {"level":"info","message":"Order Data: {\"orderId\":519,\"action\":\"BUY\",\"orderType\":\"LMT\",\"totalQuantity\":1,\"lmtPrice\":1,\"account\":\"DU1234567\",\"transmit\":true,\"tif\":\"GTC\"}"} {"level":"info","message":"singleOrder.orderId! 519"} {"level":"info","message":"Order placed with ID: 519"} {"level":"info","message":"::ffff:110.136.217.116 - - [13/Apr/2024:23:19:17 +0000] \"POST /webhooks/test HTTP/1.1\" 200 2 \"-\" \"Thunder Client (https://www.thunderclient.com)\"\n"} Error code 505 for reqId -1: Decoding error on OPEN_ORDER: unprocessed data left on queue (["","","","",null]). Please report to https://github.com/stoqey/ib {"level":"info","message":"Order 519 status: PreSubmitted"} Error code 505 for reqId -1: Decoding error on OPEN_ORDER: unprocessed data left on queue (["","","","",null]). Please report to https://github.com/stoqey/ib {"level":"info","message":"Order 519 status: PreSubmitted"}

And the complete implementation (I removed the createBracketOrder()-, getSecType()- and getOrderType()-functions for simplicity):

import * as dotenv from "dotenv";
dotenv.config({ path: __dirname + "/.env" });
import {
  IBApi,
  EventName,
  ErrorCode,
  Contract,
  SecType,
  Order,
  OrderType,
  OrderAction,
} from "@stoqey/ib";
import winston from "../config/winston";

class Broker {
  clientId: number;
  account: string;
  ib: IBApi;
  nextOrderId: number;

  constructor(_mode: string) {
    this.account =
      _mode === "LIVE"
        ? String(process.env.TWS_LIVE_ACCOUNT)
        : String(process.env.TWS_PAPER_ACCOUNT);
    this.clientId =
      _mode === "LIVE"
        ? Number(process.env.TWS_LIVE_CLIENT_ID)
        : Number(process.env.TWS_PAPER_CLIENT_ID);
    this.ib = new IBApi({
      port:
        _mode === "LIVE"
          ? Number(process.env.TWS_LIVE_PORT)
          : Number(process.env.TWS_PAPER_PORT),
    });
    this.connect();
    this.nextOrderId = 0;
    this.setupListeners();
  }

  connect() {
    this.ib
      .connect(this.clientId)
      .on(EventName.connected, () => console.log("Broker connected"));
  }

  disconnect() {
    this.ib.disconnect();
    console.log("Broker disconnected");
  }

  setupListeners() {
    this.ib
      .on(EventName.nextValidId, (orderId) => {
        this.nextOrderId = orderId;
        console.log(`Next valid order ID: ${orderId}`);
      })
      .on(EventName.error, (err: Error, code: ErrorCode, reqId: number) => {
        console.error(`Error code ${code} for reqId ${reqId}: ${err.message}`);
      })
      .on(EventName.orderStatus, (orderId: number, status: string) => {
        winston.log("info", `Order ${orderId} status: ${status}`);
        if (status === "Submitted" || status === "Filled") {
          console.log(`Order ${orderId} processed with status: ${status}`);
        }
      });
  }

  createOrder(req: any) {
    const options = req.body.options;

    // Preparing the contract based on request options
    let contract: Contract;
    if (options.secId) {
      contract = {
        secIdType: "FIGI",
        secId: options.secId,
        exchange: options.exchange,
      };
    } else {
      // Default contract definition for other secTypes
      contract = {
        symbol: options.symbol,
        exchange: options.exchange,
        currency: options.currency,
        secType: this.getSecType(req),
      };
    }

    // Handling specific contract attributes based on secType
    if (contract.secType === "STK" && options.primaryExch) {
      contract.primaryExch = options.primaryExch;
    }

    // Futures
    if (contract.secType === "FUT" && options.lastTradeDateOrContractMonth) {
      contract.lastTradeDateOrContractMonth =
        options.lastTradeDateOrContractMonth;
    }
    if (contract.secType === "FUT" && options.localSymbol) {
      contract.localSymbol = options.localSymbol;
    }
    if (contract.secType === "FUT" && options.multiplier) {
      contract.multiplier = options.multiplier;
    }

    // Single order
    const singleOrder: Order = {
      orderId: Number(this.nextOrderId++),
      action:
        options.orderAction === "BUY" ? OrderAction.BUY : OrderAction.SELL,
      orderType: this.getOrderType(req),
      totalQuantity: Number(options.quantity),
      lmtPrice: options.orderType === "LMT" ? Number(options.lmtPrice) : undefined,
      auxPrice: options.orderType.startsWith("STP")
        ? options.auxPrice
        : undefined,
      account: this.account,
      transmit: true,
      tif: options.tif,
    };
    winston.log('info', 'Contract Data: '+JSON.stringify(contract))
    winston.log('info', 'Order Data: '+JSON.stringify(singleOrder))

    // Placing the single order
    winston.log('info', 'singleOrder.orderId! ' +singleOrder.orderId!)
    this.ib.placeOrder(singleOrder.orderId!, contract, singleOrder);
    winston.log("info", `Order placed with ID: ${singleOrder.orderId}`);
  }

}

module.exports = Broker;
rylorin commented 2 months ago

Hello, I can't reproduce your issue with v1.3.19:

info Contract Data: {"symbol":"SPY","exchange":"SMART","currency":"USD","secType":"STK"}
info Order Data: {"orderId":0,"action":"BUY","orderType":"LMT","totalQuantity":1,"lmtPrice":1,"account":"undefined","transmit":true,"tif":"GTC"}
info singleOrder.orderId! 0
info Order placed with ID: 0
info Contract Data: {"symbol":"SPY","exchange":"SMART","currency":"USD","secType":"STK"}
info Order Data: {"orderId":1,"action":"BUY","orderType":"LMT","totalQuantity":1,"lmtPrice":1,"account":"undefined","transmit":true,"tif":"GTC"}
info singleOrder.orderId! 1
info Order placed with ID: 1
Broker connected
Next valid order ID: 2
Error code 10149 for reqId 0: Invalid order id: 0
info Order 1 status: PreSubmitted

I called createOrder twice because the first one failed because of a zero order Id but not decoding error.

johnpantini commented 3 weeks ago

The error started appearing again (for any orders) after the recent TWS update.

rylorin commented 3 weeks ago

Could you please confirm which release you are using?

johnpantini commented 3 weeks ago

Module version: "1.3.21"

TWS 1.30.0.16

rylorin commented 2 weeks ago

What is TWS 1.30.0.16? I have TWS 10.19.2n, dated May 22 2024. Can you provide a link to the location where you found it?

johnpantini commented 2 weeks ago

What is TWS 1.30.0.16? I have TWS 10.19.2n, dated May 22 2024. Can you provide a link to the location where you found it?

My bad, TWS 10.30.1a Jun 10, 2024 https://www.interactivebrokers.com/en/trading/tws.php TWS Beta

johnpantini commented 2 weeks ago

The issue is still here :(

mafianekcek commented 2 weeks ago

Hello, I have a similar problem since today after I reinstalled my PC and had to do use npm install again

I am using TWS build 10.29.1h, Jun 5, 2024 10:53:32 PM

here is the program output with order and other details aswell:

14/06/2024 18:49:31.197 [LOG]IB API connected (demo)
14/06/2024 18:49:31.198 [DEBUG]nextValidId: 20 
14/06/2024 18:49:31.214 [LOG][IBAPI]id: -1 / code: 2104 / Market data farm connection is OK:usfarm.nj
14/06/2024 18:49:31.215 [LOG][IBAPI]id: -1 / code: 2104 / Market data farm connection is OK:usfuture
14/06/2024 18:49:31.215 [LOG][IBAPI]id: -1 / code: 2104 / Market data farm connection is OK:usfarm
14/06/2024 18:49:31.215 [LOG][IBAPI]id: -1 / code: 2106 / HMDS data farm connection is OK:ushmds
14/06/2024 18:49:31.216 [LOG][IBAPI]id: -1 / code: 2158 / Sec-def data farm connection is OK:secdefil
14/06/2024 18:49:47.111 [DEBUG][Order 8(20)]prepareOrder: order({"side":"LONG","orderFlag":null,"secType":"FOP","symbol":"MES","tradingClass":"X3B","expiration":"20240618","action":"BUY","count":1,"strike":"5425","right":"PUT","orderType":"LMT","outsideRTH":1,"tif":"DAY","conId":"708847529","underConId":"620731036","parentSymbol":"ES","parentConId":703139398,"parentUnderConId":551601561,"exchange":"CME","multiplier":5,"currency":"USD","id":8,"insertId":8,"tradeId":3,"date":1718383787011,"comboId":null,"isNew":true,"contract":{"conId":"708847529","exchange":"CME"},"account":"DU5784856","ibApiOrderId":20,"midAdjustTick":0,"failCount":0,"firstSubmitTime":1718383787109,"lastMidUpdate":1718383787109,"lastSubmitAttemp":1718383787109,"canTransmit":false}), placeOrderType({"action":"BUY","lmtPrice":0,"totalQuantity":1,"transmit":false,"orderType":"LMT","account":"DU5784856","tif":"DAY","orderRef":"RS/3/8"})
14/06/2024 18:49:47.113 [DEBUG][Order 9(21)]prepareOrder: order({"side":"LONG","orderFlag":null,"secType":"FOP","symbol":"MES","tradingClass":"X3B","expiration":"20240618","action":"SELL","count":1,"strike":"5425","right":"CALL","orderType":"LMT","outsideRTH":1,"tif":"DAY","conId":"708846212","underConId":"620731036","parentSymbol":"ES","parentConId":703138996,"parentUnderConId":551601561,"exchange":"CME","multiplier":5,"currency":"USD","id":9,"insertId":9,"tradeId":3,"date":1718383787011,"comboId":null,"isNew":true,"contract":{"conId":"708846212","exchange":"CME"},"account":"DU5784856","ibApiOrderId":21,"midAdjustTick":0,"failCount":0,"firstSubmitTime":1718383787112,"lastMidUpdate":1718383787112,"lastSubmitAttemp":1718383787112,"canTransmit":false}), placeOrderType({"action":"SELL","lmtPrice":0,"totalQuantity":1,"transmit":false,"orderType":"LMT","account":"DU5784856","tif":"DAY","orderRef":"RS/3/9"})
14/06/2024 18:49:48.376 [DEBUG][Order 8(20)]processOrderQueue: order({"side":"LONG","orderFlag":null,"secType":"FOP","symbol":"MES","tradingClass":"X3B","expiration":"20240618","action":"BUY","count":1,"strike":"5425","right":"PUT","orderType":"LMT","outsideRTH":1,"tif":"DAY","conId":"708847529","underConId":"620731036","parentSymbol":"ES","parentConId":703139398,"parentUnderConId":551601561,"exchange":"CME","multiplier":5,"currency":"USD","id":8,"insertId":8,"tradeId":3,"date":1718383787011,"comboId":null,"isNew":true,"contract":{"conId":"708847529","exchange":"CME"},"account":"DU5784856","ibApiOrderId":20,"midAdjustTick":0,"failCount":0,"firstSubmitTime":1718383787172,"lastMidUpdate":1718383788277,"lastSubmitAttemp":1718383788376,"canTransmit":true,"parentBid":17.5,"parentAsk":18,"mid":17.75,"bid":17.5,"ask":18,"forceUpadte":false,"lastMid":17.75}), LMTOrder({"action":"BUY","lmtPrice":17.75,"totalQuantity":1,"transmit":true,"orderType":"LMT","account":"DU5784856","tif":"DAY","orderRef":"RS/3/8"})
14/06/2024 18:49:48.377 [DEBUG][Order 9(21)]processOrderQueue: order({"side":"LONG","orderFlag":null,"secType":"FOP","symbol":"MES","tradingClass":"X3B","expiration":"20240618","action":"SELL","count":1,"strike":"5425","right":"CALL","orderType":"LMT","outsideRTH":1,"tif":"DAY","conId":"708846212","underConId":"620731036","parentSymbol":"ES","parentConId":703138996,"parentUnderConId":551601561,"exchange":"CME","multiplier":5,"currency":"USD","id":9,"insertId":9,"tradeId":3,"date":1718383787011,"comboId":null,"isNew":true,"contract":{"conId":"708846212","exchange":"CME"},"account":"DU5784856","ibApiOrderId":21,"midAdjustTick":0,"failCount":0,"firstSubmitTime":1718383787172,"lastMidUpdate":1718383788277,"lastSubmitAttemp":1718383788376,"canTransmit":true,"parentBid":18.75,"parentAsk":19.25,"mid":19,"bid":18.75,"ask":19.5,"forceUpadte":false,"lastMid":19}), LMTOrder({"action":"SELL","lmtPrice":19,"totalQuantity":1,"transmit":true,"orderType":"LMT","account":"DU5784856","tif":"DAY","orderRef":"RS/3/9"})
14/06/2024 18:49:48.579 [ERROR][IBAPI]id: -1 / code: 505 / Decoding error on OPEN_ORDER: unprocessed data left on queue (["","","","",null]). Please report to https://github.com/stoqey/ib
14/06/2024 18:49:48.580 [LOG][Order 8(20)]Submitted BUY 1x FOP MES LMT 20240618 5425 PUT
14/06/2024 18:49:48.687 [ERROR][IBAPI]id: -1 / code: 505 / Decoding error on OPEN_ORDER: unprocessed data left on queue (["","","","",null]). Please report to https://github.com/stoqey/ib
14/06/2024 18:49:48.688 [LOG][Order 9(21)]Submitted SELL 1x FOP MES LMT 20240618 5425 CALL
14/06/2024 18:49:55.222 [DEBUG][Order 8(20)]processOrderQueue: order({"side":"LONG","orderFlag":null,"secType":"FOP","symbol":"MES","tradingClass":"X3B","expiration":"20240618","action":"BUY","count":1,"strike":"5425","right":"PUT","orderType":"LMT","outsideRTH":1,"tif":"DAY","conId":"708847529","underConId":"620731036","parentSymbol":"ES","parentConId":703139398,"parentUnderConId":551601561,"exchange":"CME","multiplier":5,"currency":"USD","id":8,"insertId":8,"tradeId":3,"date":1718383787011,"comboId":null,"isNew":true,"contract":{"conId":"708847529","exchange":"CME"},"account":"DU5784856","ibApiOrderId":20,"midAdjustTick":0,"failCount":0,"firstSubmitTime":1718383787172,"lastMidUpdate":1718383795017,"lastSubmitAttemp":1718383795221,"canTransmit":true,"parentBid":17.25,"parentAsk":17.75,"mid":18,"bid":17.75,"ask":18,"forceUpadte":false,"lastMid":18,"lmtPrice":17.75,"auxPrice":0,"submitted":1718383788580,"permId":2096909561,"status":"SUBMITTED"}), LMTOrder({"action":"BUY","lmtPrice":18,"totalQuantity":1,"transmit":true,"orderType":"LMT","account":"DU5784856","tif":"DAY","orderRef":"RS/3/8"})
14/06/2024 18:49:55.410 [ERROR][IBAPI]id: -1 / code: 505 / Decoding error on OPEN_ORDER: unprocessed data left on queue (["","","","",null]). Please report to https://github.com/stoqey/ib
14/06/2024 18:49:55.500 [ERROR][IBAPI]id: -1 / code: 505 / Decoding error on OPEN_ORDER: unprocessed data left on queue (["","","","",null]). Please report to https://github.com/stoqey/ib
14/06/2024 18:49:55.501 [LOG][Order 8(20)]Filled BUY 1x FOP MES LMT 20240618 5425 PUT @18
14/06/2024 18:49:55.501 [ERROR][IBAPI]id: -1 / code: 505 / Decoding error on OPEN_ORDER: unprocessed data left on queue (["","","","",null]). Please report to https://github.com/stoqey/ib
14/06/2024 18:49:56.067 [ERROR][IBAPI]id: -1 / code: 505 / Decoding error on OPEN_ORDER: unprocessed data left on queue (["","","","",null]). Please report to https://github.com/stoqey/ib
14/06/2024 18:49:56.068 [LOG][Order 9(21)]Filled SELL 1x FOP MES LMT 20240618 5425 CALL @19
14/06/2024 18:49:56.178 [ERROR][IBAPI]id: -1 / code: 505 / Decoding error on OPEN_ORDER: unprocessed data left on queue (["","","","",null]). Please report to https://github.com/stoqey/ib
rylorin commented 2 weeks ago

Sorry but once again I can't reproduce the problem:

    const refContract: Contract = {
      conId: 708846212,
      exchange: "CME",
      symbol: "MES",
    };
    const refOrder: Order = {
      action: OrderAction.BUY,
      lmtPrice: 1,
      totalQuantity: 1,
      transmit: true,
      orderType: OrderType.LMT,
      account: "DU5784856",
      tif: "DAY",
      orderRef: "RS/3/9",
    };
 PASS  src/tests/unit/api/order/placeOrder.test.ts (7.576 s)
  Place Orders
    ✓ Stock placeOrder (1034 ms)
    ✓ What if Order (803 ms)
    ✓ Crypto placeOrder (3555 ms)
    ✓ Option placeOrder (781 ms)
    ✓ Issue #203 (652 ms)

Test Suites: 1 passed, 1 total
Tests:       5 passed, 5 total
Snapshots:   0 total
Time:        9.675 s, estimated 31 s
Ran all test suites matching /.\/src\/tests\/unit\/api\/order\/placeOrder.test.ts/i.
✨  Done in 10.61s.

on TWS 10.29.1h

If somebody can contact me via PM and give me an access to his API maybe I would be able to reproduce this bug. BTW I am using node v20.12.2 on a MacBook Air M1.