[noPoll] Fixed -- Re: Websocket disconnect issues
Kale, Rahul
Rahul.Kale en barco.com
Vie Abr 22 01:48:35 CEST 2016
Hello,
Thanks for the quick turnaround to provide the fix.
However, I have a doubt about the code changes.
As you can see from my previous post, when I made local changes to the code
to see how many bytes were actually captured during the failed situation, the logs show
that instead of next 2 bytes, only one byte is captured from the wire. From your code changes
I understand that only zero byte captured case (EWOULDBLOCK) is accounted for.
I may be mistaken, but I think we need to handle the case more generically.
I see from the code that for the first 2 bytes, and later for the handling the 4 bytes of mask data,
you have already implemented correct buffering into 'pending_buf' for next attempt.
I think we will need to have similar handling for this case (as well as for
next 8 bytes of extended header for payload_size == 127 case).
I am working on integrating your current code changes into our app to see
what would happen when the situation hits. It takes quite a while to reproduce
the issue. I will let you know what I observe.
In our application, I believe that the server side always sends the full header in one shot.
However, the very nature of TCP is such that if a sender sends X bytes in one write/send call,
the receiver is not guaranteed to always get all X bytes in one read/recv call...
even if X is very small. The underlying OS networking system is free to break up the
streaming data at arbitrary boundaries. That is why the connection breaks very occasionally
and takes some time to reproduce.
Regards,
Rahul
From: Francis Brosnan Blázquez [mailto:francis.brosnan en aspl.es]
Sent: Thursday, April 21, 2016 1:52 AM
To: Kale, Rahul
Cc: nopoll en lists.aspl.es
Subject: Fixed -- Re: [noPoll] Websocket disconnect issues
Hello Rahul,
I've updated noPoll sources to reproduce the problem you described (test_30)
and added needed updates to make it work (svn revision 262):
https://github.com/ASPLes/nopoll
Check them to see if they fixes your issue,
Best Regards,
Hello Rahul,
Thanks for reporting. I'm reviewing the issue. I'll let you know something,
Best Regards,
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> [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<mailto: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>
_______________________________________________
noPoll mailing list
noPoll en lists.aspl.es<mailto:noPoll en lists.aspl.es>
http://lists.aspl.es/cgi-bin/mailman/listinfo/nopoll
--
Francis Brosnan Blázquez - ASPL
http://www.asplhosting.com/
http://www.aspl.es/
https://twitter.com/aspl_es
https://twitter.com/asplhosting
https://twitter.com/francisbrosnanb
91 134 14 22 - 91 134 14 45 - 91 116 07 57
AVISO LEGAL
En virtud de lo dispuesto en la Ley Orgánica 15/1999, de 13 de
diciembre, de Protección de Datos de Carácter Personal, le informamos de
que sus datos de carácter personal, recogidos de fuentes accesibles al
público o datos que usted nos ha facilitado previamente, proceden de
bases de datos propiedad de Advanced Software Production Line, S.L.
(ASPL).
ASPL garantiza que los datos serán tratados con la finalidad de mantener
las oportunas relaciones comerciales o promocionales con usted o la
entidad que usted representa. No obstante, usted puede ejercitar sus
derechos de acceso, rectificación, cancelación y oposición dispuestos en
la mencionada Ley Orgánica, notificándolo por escrito a ASPL -
Protección Datos, C/Antonio Suárez 10 A-102, 28802, Alcalá de Henares
(Madrid).
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/a8426705/attachment-0001.html>
Más información sobre la lista de distribución noPoll