[noPoll] Fixed -- Re: Websocket disconnect issues

Vie Abr 22 10:13:59 CEST 2016

El jue, 21-04-2016 a las 23:48 +0000, Kale, Rahul escribió:
> Hello,

Hi Rahul,

> Thanks for the quick turnaround to provide the fix.

Ok,

> 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.

Uhmn...certainly, you right...

> 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.

Ok. I'll try to update regression tests to check these cases...

Even though what you propose seems the right solution, it is a different
case 
to know that there are X pending bytes, that having broken headers
(especially
when they are so small)....this is connected to your next comment:

> In our application, I believe that the server side always sends the
> full header in one shot. 

I highly doubt it (but I may be wrong :-). 

The websocket implementation that is sending the content
is sending the header in different steps ...and because of that, the
kernel/os 
may interrupt the userland code in each of those steps....

It is nearly impossible for modern TCP stacks to present a, let's say,
packet with
6 usable bytes, and just serve some of them to the application land...

There are many obvious reasons, for example, the waste of time that
causes
for the overall performance to force userland level to call several
times to pick
just one or two bytes out of 6 bytes received...

> 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... 

You are right, but that's for bigger sizes, not for the problem we are
talking about. 

Given the costs of sending a TCP/IP packet with content, processing it,
and the fact 
that you have to avoid user land calling several times for what you have
presumable 
already received, it is clear that if the kernel has received a tcp
segment with 8 usable
bytes, it will serve them all at once...and never by pieces...

> even if X is very small. 

No,

> The underlying OS networking system is free to break up the 
> streaming data at arbitrary boundaries. 

It's free, certainly, but I as say, any modern TCP/IP stack will not do
it because it is
inconvenient...for the practical reasons exposed,

> That is why the connection breaks very occasionally
> and takes some time to reproduce.

Ok, I'll give a try to introduce more cases in the regression test so
receiving just one byte
in the particular case we are talking is also supported,

Best Regards,

> 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] 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 
> 
> 
> This message is subject to the following terms and conditions: MAIL
> DISCLAIMER
> 
>  
> 
>  
> _______________________________________________
> noPoll mailing list
> 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

-- 
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).

------------ próxima parte ------------
Se ha borrado un adjunto en formato HTML...
URL: <http://lists.aspl.es/pipermail/nopoll/attachments/20160422/069821b1/attachment-0001.html>