EvenAR / node-simconnect

A cross platform SimConnect client library for Node.JS
GNU Lesser General Public License v3.0
95 stars 33 forks source link

Busy-loop caused by subscribeToFacilitiesEx1 #91

Closed AndreKlang closed 11 months ago

AndreKlang commented 12 months ago

First of all, huge thanks for this project, everything has worked remarkably well.

I do have issues with subscribeToFacilitiesEx1 though. It usually works fine for all types except for waypoints (waypoints always fail, the others fail like 5-10% of the time). Although, if I add the "subscription" while in the world wap, I do get a small number of waypoints (<10), which is wierd in it self, because that doesn't happen for the other types.

I'm on the "current" version of MSFS 2020 Premium, steam install, all updates/packages installed, running over network. I've had this issue running the code below on a Mac, and in a docker-container on a Mac, and in a docker-container running on a linux server.

Example code (place in existing samples dir)

import { Protocol, open, FacilityListType } from '../../src';

const enum REQUEST_ID {
    NEW_WAYPOINTS = 42,
    OLD_WAYPOINTS = 43,
}

open('SimConnect sample client', Protocol.KittyHawk, {
    remote: {
        host: 'games.my-domain.se',
        port: 5151,
    }
})
    .then(({ recvOpen, handle }) => {
        console.log('Connected to sim!');

        handle.subscribeToFacilitiesEx1(
            FacilityListType.WAYPOINT,
            REQUEST_ID.NEW_WAYPOINTS,
            REQUEST_ID.OLD_WAYPOINTS
        );

        handle.on('waypointList', recvWaypointList => {
            switch (recvWaypointList.requestID) {
                case REQUEST_ID.NEW_WAYPOINTS:
                    console.log('These waypoints appeared', recvWaypointList.waypoints);
                    break;
                case REQUEST_ID.OLD_WAYPOINTS:
                    console.log('These waypoints disappeared', recvWaypointList.waypoints);
                    break;
            }
        });

        handle.on('exception', exception => {
            console.log(exception);
        });
    })
    .catch(error => {
        console.log('Failed to connect', error);
    });

I tracked the issue to here: https://github.com/EvenAR/node-simconnect/blob/master/src/SimConnectSocket.ts#L107

Changing that to:

            // Read message body
            const body: Buffer = this._socket.read(bodyLength);

            console.log(lenBuf, bodyLength, body)
            if (body === null) {
                throw new Error("STOP");
            }

            if (!body) {
                // Put header back in read buffer
                this._socket.unshift(lenBuf);
                return;
            }

Provides me with:

<Buffer 34 01 00 00> 304 <Buffer 05 00 00 00 02 00 00 00 4b 69 74 74 79 48 61 77 6b 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ... 254 more bytes>
Connected to sim!
<Buffer 65 a0 00 00> 41057 null
/path-to-my/node-simconnect/src/SimConnectSocket.ts:110
                throw new Error("STOP");

Notice the "null", that cause the while to turn into a busy-loop, completely locking up the node process.

Any idea what's going on here? Is this just me? Can it be because I'm running over network?

Btw, this expamle was tested with the current master (https://github.com/EvenAR/node-simconnect/commit/2efbe0917deb89de2fb71b89fcf2c99c074205e5) but I have the same issue with the latest release.

Thanks again for all your work!

AndreKlang commented 12 months ago

Looks like there are some size-thing at play here..

I tried to modify my modification above, playing around with different read-lengths:

            if (body === null) {
                console.log(this._socket.read(14475))
                throw new Error("STOP");
            }

At that number (14475 bytes), it mostly work, but sometimes gives null. At 15000 bytes, it gives null 6 out of 6 times.

But there's clearly data there..

<Buffer 05 00 00 00 15 00 00 00 2a 00 00 00 54 04 00 00 00 00 00 00 03 00 00 00 56 50 43 54 45 00 4b 37 00 00 00 40 e2 9b 27 3a 40 00 00 60 7b 14 56 54 c0 00 ... 14425 more bytes>
EvenAR commented 12 months ago

Hi @AndreKlang! I'm glad to hear you like the project! And thanks for the detailed issue description 🙏

Interesting bug. Looking closer at the docs for readable it's not unlikely that this is related to running over network. Large SimConnect messages are probably more likely to be split into chunks when transferred over the TCP protocol versus over the local named pipes. According to the docs read() will return null if not all the requested bytes are available in the readable's internal buffer, and it will not block until all bytes are received which I must have assumed when I wrote this.

The fix is probably what the docs (which I obviously haven't studied that well) recommends, to collect chunks until the expected bytes are received (using read() instead of read(bodyLength)).

I might be able to look into this next week, but feel free to open a PR if you find a solution :)

PS: one must take into account that one chunk of bytes could in theory contain both the end of one SimConnect message and the beginning of a new SimConnect message. So it’s slightly more complicated than a while-loop I suppose..

AndreKlang commented 12 months ago

Thanks for the quick feedback!

That made total sense, so I looked into it a little more. There are a this._socket.readableLength, which contain the length currently available.

I'm thinking of using that instead of an un-bounded read(), to avoid getting bytes for the next message. Proof-of-concept PR on the way!