stoqey / ib

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

Getting testing setup #86

Closed mikedavies-dev closed 3 years ago

mikedavies-dev commented 3 years ago

Hey all,

I've noticed an issue with reqHistoricalTicks that I'd like to fix and add associated tests but I'm having getting the test suit up and running. I'm probably missing something in my setup.

I'm running IB Gateway on port 4002 (paper trading account) and a lot of the API tests seem to work (i.e. I can see the test suite connecting to IB Gateway etc), but a lot of the tests timeout (test results below). The test suite is obviously connecting to IB Gateway in some tests because I can see active connections there and a lot of the API tests pass OK.

I've also tried running the docker image but that shows connection errors on 4002. I'm not sure if that needs to be running for the tests to work?

Any thoughts on what I might be missing in my dev setup?

yarn run v1.22.10
$ jest --maxWorkers=8 --reporters=default --useStderr --detectOpenHandles
 FAIL  src/tests/unit/api/api.test.ts (61.007 s)
  ● IBApi Tests › Test connect / disconnect

    : Timeout - Async callback was not invoked within the 30000 ms timeout specified by jest.setTimeout.Timeout - Async callback was not invoked within the 30000 ms timeout specified by jest.setTimeout.Error:

      13 |   let _clientId = 0; // ensure unique client
      14 | 
    > 15 |   it("Test connect / disconnect", (done) => {
         |   ^
      16 |     const ib = new IBApi({
      17 |       clientId: _clientId++,
      18 |       host: TEST_SERVER_HOST,

      at new Spec (node_modules/jest-jasmine2/build/jasmine/Spec.js:116:22)
      at Suite.<anonymous> (src/tests/unit/api/api.test.ts:15:3)

  ● IBApi Tests › Test reqPositions / cancelPositions

    expect(received).toBeFalsy()

    Received: "connect EADDRNOTAVAIL 127.0.0.1 - Local (0.0.0.0:49365) - code: 502 - id: -1"

      46 | 
      47 |     ib.on(EventName.error, (err: Error, code: ErrorCode, id: number) => {
    > 48 |       expect(`${err.message} - code: ${code} - id: ${id}`).toBeFalsy();
         |                                                            ^
      49 |     })
      50 |       .on(
      51 |         EventName.position,

      at IBApi.<anonymous> (src/tests/unit/api/api.test.ts:48:60)
      at IBApi.emit (node_modules/eventemitter3/index.js:183:35)
      at Controller.emitEvent (src/core/io/controller.ts:168:13)
      at Controller.emitError (src/core/io/controller.ts:207:10)
      at Socket.onError (src/core/io/socket.ts:421:21)
      at Socket.<anonymous> (src/core/io/socket.ts:148:36)

  ● IBApi Tests › Test reqPnL / cancelPositions

    expect(received).toBeFalsy()

    Received: "Server Version 0: It does not support position requests. - code: 503 - id: -1"

      46 | 
      47 |     ib.on(EventName.error, (err: Error, code: ErrorCode, id: number) => {
    > 48 |       expect(`${err.message} - code: ${code} - id: ${id}`).toBeFalsy();
         |                                                            ^
      49 |     })
      50 |       .on(
      51 |         EventName.position,

      at IBApi.<anonymous> (src/tests/unit/api/api.test.ts:48:60)
      at IBApi.emit (node_modules/eventemitter3/index.js:183:35)
      at Controller.emitEvent (src/core/io/controller.ts:168:13)
      at Controller.emitError (src/core/io/controller.ts:207:10)
      at Encoder.emitError (src/core/io/encoder.ts:179:19)
      at Encoder.reqPositions (src/core/io/encoder.ts:2414:19)
      at src/api/api.ts:1239:60
      at src/core/io/controller.ts:84:34
      at Controller.execute (src/core/io/controller.ts:220:5)
      at CommandBuffer.Object.<anonymous>.CommandBuffer._process (node_modules/command-buffer/dist/command-buffer.js:65:16)

  ● IBApi Tests › Test reqPnLSingle / cancelPnLSingle

    : Timeout - Async callback was not invoked within the 30000 ms timeout specified by jest.setTimeout.Timeout - Async callback was not invoked within the 30000 ms timeout specified by jest.setTimeout.Error:

      102 |   });
      103 | 
    > 104 |   it("Test reqPnLSingle / cancelPnLSingle", (done) => {
          |   ^
      105 |     const ib = new IBApi({
      106 |       clientId: _clientId++,
      107 |       host: TEST_SERVER_HOST,

      at new Spec (node_modules/jest-jasmine2/build/jasmine/Spec.js:116:22)
      at Suite.<anonymous> (src/tests/unit/api/api.test.ts:104:3)

 FAIL  src/tests/unit/api/order/placeOrder.test.ts (20.321 s)
  ● RequestAllOpenOrders › placeOrder with PriceCondition

    Failed: undefined

      72 |       }).on(EventName.openOrderEnd, () => {
      73 |         if (!finished) {
    > 74 |           fail();
         |           ^
      75 |         }
      76 |       });
      77 | 

      at Env.fail (node_modules/jest-jasmine2/build/jasmine/Env.js:722:61)
      at IBApi.<anonymous> (src/tests/unit/api/order/placeOrder.test.ts:74:11)
      at IBApi.emit (node_modules/eventemitter3/index.js:180:35)
      at Controller.emitEvent (src/core/io/controller.ts:168:13)
      at src/core/io/decoder.ts:381:23
          at Array.forEach (<anonymous>)
      at Decoder.process (src/core/io/decoder.ts:380:14)
      at Controller.processIngressQueue (src/core/io/controller.ts:100:18)
      at Socket.onMessage (src/core/io/socket.ts:303:23)

  ● RequestAllOpenOrders › placeOrder with PriceCondition

    : Timeout - Async callback was not invoked within the 20000 ms timeout specified by jest.setTimeout.Timeout - Async callback was not invoked within the 20000 ms timeout specified by jest.setTimeout.Error:

      18 |   jest.setTimeout(20000);
      19 | 
    > 20 |   test("placeOrder with PriceCondition", (done) => {
         |   ^
      21 |     const ib = new IBApi({
      22 |       port: 4002, // use Gateway
      23 |     });

      at new Spec (node_modules/jest-jasmine2/build/jasmine/Spec.js:116:22)
      at Suite.<anonymous> (src/tests/unit/api/order/placeOrder.test.ts:20:3)

 FAIL  src/tests/unit/api/order/reqAllOpenOrders.test.ts (20.252 s)
  ● Console

    console.log
      Using host: undefined and port: undefined for test

      at Object.info (src/common/logger.ts:15:42)

  ● RequestAllOpenOrders › Test reqAllOpenOrders

    : Timeout - Async callback was not invoked within the 20000 ms timeout specified by jest.setTimeout.Timeout - Async callback was not invoked within the 20000 ms timeout specified by jest.setTimeout.Error:

      12 | describe("RequestAllOpenOrders", () => {
      13 |   jest.setTimeout(20000);
    > 14 |   it("Test reqAllOpenOrders", (done) => {
         |   ^
      15 |     logger.info(
      16 |       `Using host: ${TEST_SERVER_HOST} and port: ${TEST_SERVER_POST} for test `
      17 |     );

      at new Spec (node_modules/jest-jasmine2/build/jasmine/Spec.js:116:22)
      at Suite.<anonymous> (src/tests/unit/api/order/reqAllOpenOrders.test.ts:14:3)

 FAIL  src/tests/unit/configuration.test.ts
  ● configuration › ENV vars take priority

    expect(received).toEqual(expected) // deep equality

    Expected: "ENV"
    Received: undefined

       7 | describe("configuration", () => {
       8 |   test("ENV vars take priority", async () => {
    >  9 |     expect(configuration.env_config_test).toEqual("ENV");
         |                                           ^
      10 |   });
      11 | 
      12 |   test("ENV vars must be specified in includes array", async () => {

      at Object.<anonymous> (src/tests/unit/configuration.test.ts:9:43)

  ● configuration › ENV vars must be specified in includes array

    expect(received).toEqual(expected) // deep equality

    Expected: "default"
    Received: undefined

      11 | 
      12 |   test("ENV vars must be specified in includes array", async () => {
    > 13 |     expect(configuration.env_not_included_config_test).toEqual("default");
         |                                                        ^
      14 |   });
      15 | 
      16 |   test("environment specific files take priority over local", async () => {

      at Object.<anonymous> (src/tests/unit/configuration.test.ts:13:56)

  ● configuration › environment specific files take priority over local

    expect(received).toEqual(expected) // deep equality

    Expected: "test"
    Received: undefined

      16 |   test("environment specific files take priority over local", async () => {
      17 |     const env = configuration.ci ? "development" : "test";
    > 18 |     expect(configuration.environment_config_test).toEqual(env);
         |                                                   ^
      19 |   });
      20 | 
      21 |   test("local takes priority over default", async () => {

      at Object.<anonymous> (src/tests/unit/configuration.test.ts:18:51)

  ● configuration › local takes priority over default

    expect(received).toEqual(expected) // deep equality

    Expected: "local"
    Received: undefined

      21 |   test("local takes priority over default", async () => {
      22 |     if (!configuration.ci) {
    > 23 |       expect(configuration.local_config_test).toEqual("local");
         |                                               ^
      24 |     }
      25 |   });
      26 | 

      at Object.<anonymous> (src/tests/unit/configuration.test.ts:23:47)

  ● configuration › default is lowest priority

    expect(received).toEqual(expected) // deep equality

    Expected: "default"
    Received: undefined

      26 | 
      27 |   test("default is lowest priority", async () => {
    > 28 |     expect(configuration.default_config_test).toEqual("default");
         |                                               ^
      29 |   });
      30 | });
      31 | 

      at Object.<anonymous> (src/tests/unit/configuration.test.ts:28:47)

 PASS  src/tests/unit/api-next/get-account-summary.test.ts

  ●  Cannot log after tests are done. Did you forget to wait for something async in your test?
    Attempted to log "Error: connect EADDRNOTAVAIL 127.0.0.1 - Local (0.0.0.0:49374)
        at Controller.emitError (/Users/miked/Projects/temp/ib2/src/core/io/controller.ts:207:37)
        at Socket.onError (/Users/miked/Projects/temp/ib2/src/core/io/socket.ts:337:25)
        at Socket.<anonymous> (/Users/miked/Projects/temp/ib2/src/core/io/socket.ts:117:42)
        at Socket.emit (events.js:314:20)
        at emitErrorNT (internal/streams/destroy.js:100:8)
        at emitErrorCloseNT (internal/streams/destroy.js:68:3)
        at processTicksAndRejections (internal/process/task_queues.js:80:21)".

      26 |   );
      27 | 
    > 28 |   console.error(...newArgs);
         |           ^
      29 | };
      30 | 
      31 | const testError = (...args: any[]) => {

      at BufferedConsole.error (node_modules/@jest/console/build/BufferedConsole.js:161:10)
      at Object.error (src/common/logger.ts:28:11)
      at IBApi.<anonymous> (src/tests/unit/api/connect.test.ts:30:14)
      at IBApi.emit (node_modules/eventemitter3/index.js:183:35)
      at Controller.emitEvent (src/core/io/controller.ts:168:13)
      at Controller.emitError (src/core/io/controller.ts:207:10)
      at Socket.onError (src/core/io/socket.ts:421:21)
      at Socket.<anonymous> (src/core/io/socket.ts:148:36)

 PASS  src/tests/unit/api/connect.test.ts
  ● Console

    console.error
      Error: Cannot disconnect if already disconnected.
          at Controller.emitError (/Users/miked/Projects/temp/ib2/src/core/io/controller.ts:207:37)
          at Controller.executeDisconnect (/Users/miked/Projects/temp/ib2/src/core/io/controller.ts:249:12)
          at Controller.disconnect (/Users/miked/Projects/temp/ib2/src/core/io/controller.ts:74:10)
          at IBApi.disconnect (/Users/miked/Projects/temp/ib2/src/api/api.ts:137:21)
          at Object.<anonymous> (/Users/miked/Projects/temp/ib2/src/tests/unit/api/connect.test.ts:22:10)
          at Object.asyncJestLifecycle (/Users/miked/Projects/temp/ib2/node_modules/jest-jasmine2/build/jasmineAsyncInstall.js:58:37)
          at /Users/miked/Projects/temp/ib2/node_modules/jest-jasmine2/build/queueRunner.js:45:12
          at new Promise (<anonymous>)
          at mapper (/Users/miked/Projects/temp/ib2/node_modules/jest-jasmine2/build/queueRunner.js:28:19)
          at /Users/miked/Projects/temp/ib2/node_modules/jest-jasmine2/build/queueRunner.js:75:41

      26 |   );
      27 | 
    > 28 |   console.error(...newArgs);
         |           ^
      29 | };
      30 | 
      31 | const testError = (...args: any[]) => {

      at Object.error (src/common/logger.ts:28:11)
      at IBApi.<anonymous> (src/tests/unit/api/connect.test.ts:30:14)
      at IBApi.emit (node_modules/eventemitter3/index.js:183:35)
      at Controller.emitEvent (src/core/io/controller.ts:168:13)
      at Controller.emitError (src/core/io/controller.ts:207:10)
      at Controller.executeDisconnect (src/core/io/controller.ts:249:12)
      at Controller.disconnect (src/core/io/controller.ts:74:10)
      at IBApi.disconnect (src/api/api.ts:137:21)

 PASS  src/tests/unit/api-next/get-contract-details.test.ts
 PASS  src/tests/unit/api-next/get-managed-accounts.test.ts
 PASS  src/tests/unit/api-next/get-market-data.test.ts
 PASS  src/tests/unit/api-next/get-historical-data.test.ts
 PASS  src/tests/unit/api-next/get-pnl.test.ts
 PASS  src/tests/unit/api-next/get-pnl-signle.test.ts
 PASS  src/tests/unit/api-next/get-positions.test.ts
 PASS  src/tests/unit/api-next/get-historical-data-updates.test.ts
 PASS  src/tests/unit/api-next/get-current-time.test.ts
 PASS  src/tests/unit/api-next/ib-api-next-map.test.ts

Test Suites: 4 failed, 12 passed, 16 total
Tests:       11 failed, 32 passed, 43 total
Snapshots:   0 total
Time:        103.334 s
Ran all test suites.
mikedavies-dev commented 3 years ago

It seems to be an issue with the configuration and the read function:

function read(file: string): Configuration {
  const filePath = path.resolve(
    __dirname,
    "..",
    "..",
    "config",
    `${file}.json`
  );
  return readJson(filePath);
}

That function resolves to src/config/default.json instead of config/default.json so it can't find the default or local config files. I'm guessing this could be a platform specific issue? I'm on MacOS. If I correct that function the tests connect to IB.

Another issue I'm seeing is with the Test reqPositions / cancelPositions test. It appears to expect at least one open position to pass. Should these tests only be run when there are open positions in the paper trading account?

Thanks again.

mfrener commented 3 years ago

The testing code still is pretty incomplete unfortunately and some also involve manual steps first (i.e. you must have a position to test reqPositions) . Only api-next tests run on CI right now as they only test the RxJS wrapper, but no actual tests against TWS are run (mainly because we don't have any spare paper accounts left that be used on CI). So if you want to add test code for reqHistoricalTicks, feel free to do so. There are no requirements on how it must look like, as we are still on "code gathering" phase. So better to have something, than nothing - we will build a full automated test-bed as soon as we have enough testing code and IB decides to sponsor some paper account for CI.

About the src-folder issue, I think it is a bug, but waiting on @Tsopic feedback.

Tsopic commented 3 years ago

Yeh, there seem to be at least 2 problems with configuration.ts

1) The location of the configuration.ts should be /src/common and not buried deep somewhere. 2) envsToInclude is missing most of the attributes, that we would want to include from env (IB_PORT, IB_HOST etc)

mikedavies-dev commented 3 years ago

OK great, thanks for the feedback. I'll add a test or two for reqHistoricalTicks. If you like i can take a look at the config issues as well while I'm there.

Tsopic commented 3 years ago

Hey, @ant-fx is this resolved? :)