[gnutls-help] Regression bug between 2.x and 3.2?

Lavrentiev, Anton (NIH/NLM/NCBI) [C] lavr at ncbi.nlm.nih.gov
Fri Jun 13 18:21:23 CEST 2014


>  Could you provide a gnutls trace (use GNUTLS_DEBUG_LEVEL=6 or more),

With GNUTLS 3.2.13, here's the point of failure (SSOCK#1000 is our callback's output that shows that it
could write only 528 bytes -- GNUTLS was pushing 1053).  After that the control gets back from
gnutls_record_send() with a GNUTLS_E_EAGAIN return code rather than the callback is tried one
more time (it's how send() should have been used).  Note that we're using non-blocking output
in the callback.  So when the device is full, it won't accept any data at all and won't block,
so the callback does a short wait, then tries again and returns immediately if anything at all
has been written successfully.

---BEGIN---
06/13/14 11:12:59 GNUTLS7: WRITE FLUSH: 1053 bytes in buffer.
06/13/14 11:12:59 SSOCK#1000[3]@130.14.29.110:443: Written at offset 17469
#################### [BEGIN] Raw Data (528 bytes):
\27\3\3\4\30\0\0\0\0\0\0\0\22\222\321\351\267\357\22343[\243\361\213\341,\275\36\342\214\35\200S\241\240\27\324\n\
q7\347  \\\377\257\20\2\20W%Z\241\224\241JX\250\"_\240\23iX3\205f\373<@G\344\260\246KS\262\33\313*\216\231I\356\223\260\342\343\b\216\267\234\372\256&\256\300\367+\350iLmq\226=\21
h\245@\343\364\223t\220+\34%kTs\37}\234\335-\307\216\205\202\357@:\254\253\223{/\265\237i \3678\1|t\2441%v\252\246|\34\335\31\355\215\3\207\311\20\27\316\36CG[^\331\245\336d\261R\
#################### [END] Raw Data

06/13/14 11:12:59 GNUTLS7: WRITE: wrote 528 bytes, 525 bytes left.
---END---
At this point I get GNUTLS_E_EAGAIN from gnutls_record_send(), presumably because this gets executed in gnutls_buffers.c:
        if (sent < tosend) {
                return gnutls_assert_val(GNUTLS_E_AGAIN);
        }


GNUTLS 2.4.2 behaves differently, it calls the push function again even after a short write.
Unable to write anything right away, our push function waits for the output device to become
ready, and writes the next portion of the buffer, thus the entire writing process advances.

---BEGIN---
06/13/14 11:59:33 GNUTLS4: REC[15f42120]: Sending Packet[2033] Application Data(23) with length: 1024
06/13/14 11:59:33 GNUTLS7: WRITE: Will write 1301 bytes to 368319552.
06/13/14 11:59:33 SSOCK#1000[0]@130.14.29.110:443: Written at offset 2403083
#################### [BEGIN] Raw Data (480 bytes):
\27\3\2\5\20\306Uq\367\t\36#\330D\257x\v\341:})z\246o\334\213y4kN\2213>\236\345\350h\21\245O\305\21Q\263\270\203\245V`\236\200\330\250Xr\264xQ\225_\267*\30r#\350\237*\257:\251n\32
\245\v\6\252\4R\21\34\241\364$o@\250\353\222/\235\336\355\0\334\351\270\206\350\5g\20\b\333\372:5\300\350\373\330\265\265%\261F\266!\36\0[\207\364\343\b\242Xr\221\346X\251k\301\n\
\210\212kdA\334\321\276\'\374%\332t\3204\5\216\3354\335;o&\277\262\206\265\376\337V&\25&\26\25\0236\310^\n\
\247\301Yk\324\235\202\261\277}vt\3069<\375vo\n\
 \262\250\272\21xTL(\240\207\317\333I\347C\316Z3\372\260;G\2479D\353\24\20\200!\240\37o\26\225\350\324\206sf\305i{\a\331\20*\252/\302\314`\35472\256#/6;R\367\351\2535\22\326\331\3
#################### [END] Raw Data

06/13/14 11:59:33 GNUTLS7: WRITE: wrote 480 bytes to 368319552. Left 821 bytes. Total 1301 bytes.
...
06/13/14 11:59:33 SSOCK#1000[0]@130.14.29.110:443: Written at offset 2403563
#################### [BEGIN] Raw Data (821 bytes):
\206\363\273;\aj\306U\210pc9D\a\fU+=\5\367\33\"\324\253\224\27\254v(\27\325e\216\2023\247\310\233Es\325s\343\242H\2704rx\tD\23\361zS\252R\v\201bl\231\222Q\377\334n\205l\330o\322a\
\337(\305H\242n\260\252@\210\260\6\272\214\311\4\317R\234\344,Vu\0045\325z3\235\177\311&\344\307e\327\242\261\344\374\350t\204&W\253\205\361\271\251\326U\330\355\327\255{\331Zb\26
\335L\2W\v\215\271\334!\202c_\\)\304\215Y\303N2\363L\265\221s\356.\17h\215 o7\376\6\225\344\26\276\370I\240\226\260Npe\301\321\231\231\3361\36[\357\206n\304c\302\302\201\307\233F\
\216\240\306\222\357\207/C\230=\2126~y<VIR8\303H\372\337u_q<^\"\351 gf\262@\25[\23tjm\221\354\353\252\b\177\217\227\222\370^\2336\300x\246\370\5\32\353\303\246PB%\r\210.p\315\',\3
#################### [END] Raw Data

06/13/14 11:59:33 GNUTLS7: WRITE: wrote 821 bytes to 368319552. Left 0 bytes. Total 1301 bytes.
---END---


mini-eagain.c is not a good test, IMO.  It operates buffers that fit into internal socket
buffers entirely, and uses very short messaging that can't cause the data flood in one
direction, stalling the connection (it's when send() will experience the short write
situation).  Or the client has to be faster pushing the data to the server so that the
connection becomes full at one point.  Using blocking I/O will save the trouble, but
non-blocking will demonstrate the regression.  I'll try to come up with a useful and
short reproducer, though...


Anton Lavrentiev
Contractor NIH/NLM/NCBI




More information about the Gnutls-help mailing list