[noPoll] Websocket disconnect issues

[Kale, Rahul]

Hello,

I have some more debug information regarding this issue.

To confirm the conjecture that the next two bytes may not always be immediately available,
I made a local modification as shown below and ran the test again waiting for next failure.
Instead of immediately aborting the connection when this situation occurs, I poll the connection
for a short duration to see if the next two bytes appear subsequently, and then abort the connection anyway.

} else if (msg->payload_size == 126) {
        /* get extended 2 bytes length as unsigned 16 bit
        unsigned integer */
        bytes = __nopoll_conn_receive (conn, buffer + 2, 2);
        if (bytes != 2) {
            int i;
            nopoll_log (conn->ctx, NOPOLL_LEVEL_CRITICAL, "Failed to get next 2 bytes to read header from the wire (read %d, %d), failed to received content, shutting down id=%d the connection", bytes, errno, conn->id);
            for (i = 0; i < 100; i++) {
                bytes = __nopoll_conn_receive (conn, buffer + 2, 2);
                if (bytes == 2) {
                    nopoll_log (conn->ctx, NOPOLL_LEVEL_CRITICAL, "Finally got next 2 bytes to read header from the wire after %d tries, shutting down anyway id=%d the connection", i, conn->id);
                    break;
                }
                nopoll_sleep(10); // 10 ms sleep
            }
            nopoll_msg_unref (msg);
            nopoll_conn_shutdown (conn);
            return NULL;
    } /* end if */

The above is just a local change to confirm the root cause.

I reproduced the disconnection bug again and from the logs, you can see that only one byte was available initially
and after a very short duration we do get the remaining bytes.

The relevant log lines look like:

nopoll_conn.c:2798 Failed to get next 2 bytes to read header from the wire (read 1, 0), failed to received content, shutting down id=2 the connection
nopoll_conn.c:2802 Finally got next 2 bytes to read header from the wire after 5 tries, shutting down anyway id=2 the connection

I think, not getting next 2 (or 4 bytes) should not be treated as an error situation, but rather treated as
full message not yet available just like when waiting for the first two bytes of the message. The call is supposed to be
non-blocking so we of course cannot poll like the test code snippet above.

Do let me know if you need any further info.
This issue is very critical to move forward with our current application.

Regards,

Rahul


From: nopoll-bounces en lists.aspl.es [mailto:nopoll-bounces en lists.aspl.es] On Behalf Of Kale, Rahul
Sent: Tuesday, April 19, 2016 6:33 PM
To: nopoll en lists.aspl.es
Subject: [noPoll] Websocket disconnect issues


Hello,

I have been trying to track down a random websocket disconnection issue that we are facing.
In our application, after some random number of hours of a good websocket connection that is
transferring data back and forth, the connection suddenly breaks. We are using noPoll only
for the client side of a WebSocket connection. The server side is Apache frontend with
node app backend.

After eliminating all other probable causes, I enabled noPoll debug logs and was finally able
to catch the error which causes a disconnect:

nopoll_conn.c:2797 Failed to get next 2 bytes to read header from the wire, failed to received content, shutting down id=2 the connection

Reproducing this is difficult since it takes anything from a couple of hours to a couple of days
but eventually it happens. My debugging efforts at narrowing this down is thus taking quite a while.

We are using secure web sockets (wss://).

Looking at the code, it seems that in the noPoll library, we expect the next two bytes of
the websocket header to be always available if we read the first two bytes.
I think that over TCP (and possibly even more so over TLS)
this may not always be guaranteed. The socket is non-blocking and it may occasionally
have a pattern that 4 bytes are split over two (or more) TCP segments.

For reading first two bytes noPoll library seems to be buffering if data is not available.
For correctness, should this be done for subsequent parts of the header too?
Of course, I am not an expert here so could you analyze and let me know what is could
be the root cause? What should be my next steps?

I have already verified that this is not due to http(s) server error. I did a TCP dump
and confirmed that when this happens, the first FIN is sent by the client (noPoll) to the http server.


Regards,

Rahul

Rahul Kale

IP Video Systems
Barco, Inc
1287 Anvilwood Ave
Sunnyvale, CA  94089

Tel  +1 408 400 4238

This message is subject to the following terms and conditions: MAIL DISCLAIMER<http://www.barco.com/en/maildisclaimer>
This message is subject to the following terms and conditions: MAIL DISCLAIMER<http://www.barco.com/en/maildisclaimer>
------------ próxima parte ------------
Se ha borrado un adjunto en formato HTML...
URL: <http://lists.aspl.es/pipermail/nopoll/attachments/20160421/2401386d/attachment.html>