You are not logged in. Please login or register.
Please post questions or comments you have about wolfSSL products here. It is helpful to be as descriptive as possible when asking your questions.
ReferenceswolfSSL - Embedded SSL Library → Posts by carlo
Pages 1
Thank you! It seems I totally misunderstood what max fragment length meant. Based on this explanation it is now clear to me that I do not need it and I'll remove it from my library 
.
Note: the reason that I thought I needed it is because DO need to know what the fragmentation size is in order to avoid less efficient communications; and I thought that without the negotiation it would be rather arbitrary (depending on the server) and that it could differ between servers.
Is there documentation about this? Or what does it do?
The above code (including reasoning) then leads to the following:
ThreadPool16 TLS : Entering TLS::do_handshake()
ThreadPool16 TLS : wolfSSL_connect((WOLFSSL*)0x7f023c0018d0) = <unfinished>
ThreadPool16 EVIO : Entering TLS::send(0x7f023c00c280, 320) [(WOLFSSL*)0x7f023c0018d0, FD:0x560b46510c80]
ThreadPool16 SYSTEM : send(15, "\x16\x03\x03\x01;\x01\x00\x017\x03\x03&\xD2(Z\xB0\xC8\xF0LP\x92r:\x10\n=\xFCH" \xF4!?\xDC0\xE6\x9F\x1F\xA1Q\xD5{\xD3\x00\x00X\x13\x01\x13\x02\x13\x03\x13\x04\x13\x05\xC0\xB4\xC0\xB5\xC0,\xC0+\xC00\xC0/\x00\x9F\x00\x9E\xCC\xA9\xCC\xA8\xCC\xAA\xC0'\xC0#\xC0(\xC0$\xC0\n\xC0\t\xC0\a\xC0\b\xC0\x14\xC0\x13\xC0\x11\xC0\x12\xC0\xAC\xC0\xAE\xC0\xAF\x00k\x00g\x009\x003\x00\x16\xCC\x14\xCC\x13\xCC\x15\xC0\x06\x00E\x00\x88\x00\xBE\x00\xC4\x01\x00\x00\xB6\x003\x00G\x00E\x00\x17\x00A\x04*\xB6!\xD4//\xCBk\xD4\xDA\xE0+#T,*\xEAN\xEDF\xA4\xED5\xE8\xDE\xA7\xE7\xC8\\\x84\x14#\xB1j\x7Fl\x11H\xE5\xE1\x03\x80\xC1\a\x1CBj\x0E\xBD\xC3\xA7\xFB\x12\x99\xDD2b\x17\x92,rb\x0F|\x00+\x00\t\b\x03\x04\x03\x03\x03\x02\x03\x01\x00\r\x00"\x00 \x06\x03\x05\x03\x04\x03\x02\x03\b\a\b\x06\b\v\b\x05\b\n\b\x04\b\t\x06\x01\x05\x01\x04\x01\x03\x01\x02\x01\x00\v\x00\x02\x01\x00\x00\n\x00&\x00$\x00\x19\x00\x1C\x00\x18\x00\e\x00\x1E\x00\x17\x00\x16\x00\x1A\x00\x1D\x00\x15\x00\x14\x00\x13\x00\x12\x00\x10\x00\x11\x00\x0F\x01\x01\x01\x00\x00\x16\x00\x00\x00\x17\x00\x00", 320, 0) = 320
ThreadPool16 EVIO : Entering TLS::recv(0x7f023c001b98, 5) [(WOLFSSL*)0x7f023c0018d0, FD:0x560b46510c80]
ThreadPool16 SYSTEM : recv(15, {"\x16\x03\x03\x00Z"}, 5, 0) = 5
ThreadPool16 EVIO : Entering TLS::recv(0x7f023c00cbb0, 90) [(WOLFSSL*)0x7f023c0018d0, FD:0x560b46510c80]
EventLoopThr SYSTEM : <continued> 1
ThreadPool16 SYSTEM : recv(15, {"\x02\x00\x00V\x03\x03\x83\xA3\xBCa"\xA1.\xB7\xAC\b\xC9N, \xAC\x1D\xAFk\x8E\xAB\x9Ep\x01\xEBa\xFC\x9AQ~>\xE8\xE9 \\\x7F\b\xED%#9\xB0P\xCE)]\x10\xE6X\xFE\xA8n\x1F\xA1\xC4~\x8B7?\xB3\xFC9)\x9F\xD1\xF8\xC00\x00\x00\x0E\x00\x16\x00\x00\x00\v\x00\x02\x01\x00\x00\x17\x00\x00"}, 90, 0) = 90
EventLoopThr EVIO : epoll_pwait event(s) EPOLLOUT of fd FD:0x560b46510c80 ignored because the event(s) EPOLLOUT is/are already being handled by the thread pool.
EventLoopThr SYSTEM : epoll_pwait() = <unfinished>
ThreadPool16 EVIO : Entering TLS::recv(0x7f023c001b98, 5) [(WOLFSSL*)0x7f023c0018d0, FD:0x560b46510c80]
EventLoopThr SYSTEM : FD:0x560b46510c80: 15, FDS_RW|FDS_R_OPEN|FDS_W_OPEN|FDS_SAME|FDS_R_ADDED|FDS_W_ADDED|FDS_R_ACTIVE|FDS_W_ACTIVE
ThreadPool16 SYSTEM : recv(15, {"\x16\x03\x03\x04\xAC"}, 5, 0) = 5
EventLoopThr SYSTEM : <continued> 1
EventLoopThr EVIO : epoll_pwait event(s) EPOLLOUT of fd FD:0x560b46510c80 ignored because the event(s) EPOLLOUT is/are already being handled by the thread pool.
ThreadPool16 EVIO : Entering TLS::recv(0x7f023c00cc20, 1196) [(WOLFSSL*)0x7f023c0018d0, FD:0x560b46510c80]
EventLoopThr EVIO : epoll_pwait new event(s): EPOLLIN
EventLoopThr EVIO : Queuing I/O event EPOLLIN for FD:0x560b46510c80 in thread pool queue #0
EventLoopThr SYSTEM : epoll_pwait() = <unfinished>
EventLoopThr SYSTEM : FD:0x560b46510c80: 15, FDS_RW|FDS_R_OPEN|FDS_W_OPEN|FDS_SAME|FDS_R_ADDED|FDS_W_ADDED|FDS_R_ACTIVE|FDS_W_ACTIVE
ThreadPool10 THREADPOOL : Beginning of thread pool main loop (q = #0)
ThreadPool10 THREADPOOL : Not going idle.
ThreadPool10 EVIO : Beginning of handling event EPOLLIN for FD:0x560b46510c80.
ThreadPool10 EVIO : Entering TLSSocket::read_from_fd({1}, 15) [FD:0x560b46510c80]
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool16 SYSTEM : recv(15, {"\v\x00\x04\xA8\x00\x04\xA5\x00\x04\xA20\x82\x04\x9E0\x82\x03\x86\xA0\x03\x02\x01\x02\x02\x01\x010\r\x06\t*\x86H\x86\xF7\r\x01\x01\v\x05\x000\x81\x941\v0\t\x06\x03U\x04\x06\x13\x02US1\x100\x0E\x06\x03U\x04\b\f\aMontana1\x100\x0E\x06\x03U\x04\a\f\aBozeman1\x110\x0F\x06\x03U\x04\n\f\bSawtooth1\x130\x11\x06\x03U\x04\v\f\nConsulting1\x180\x16\x06\x03U\x04\x03\f\x0Fwww.wolfssl.com1\x1F0\x1D\x06\t*\x86H\x86\xF7\r\x01\t\x01\x16\x10info@wolfssl.com0\x1E\x17\r180413152310Z\x17\r210107152310Z0\x81\x901\v0\t\x06\x03U\x04\x06\x13\x02US1\x100\x0E\x06\x03U\x04\b\f\aMontana1\x100\x0E\x06\x03U\x04\a\f\aBozeman1\x100\x0E\x06\x03U\x04\n\f\awolfSSL1\x100\x0E\x06\x03U\x04\v\f\aSupport1\x180\x16\x06\x03U\x04\x03\f\x0Fwww.wolfssl.com1\x1F0\x1D\x06\t*\x86H\x86\xF7\r\x01\t\x01\x16\x10info@wolfssl.com0\x82\x01"0\r\x06\t*\x86H\x86\xF7\r\x01\x01\x01\x05\x00\x03\x82\x01\x0F\x000\x82\x01\n\x02\x82\x01\x01\x00\xC0\x95\b\xE1WA\xF2qm\xB7\xD2EA'\x01e\xC6E\xAE\xF2\xBC$0\xB8\x95\xCE/N\xD6\xF6\x1C\x88\xBC|\x9F\xFB\xA8g\x7F\xFE\\\x9CQu\xF7\x8A\xCA\a\xE75/\x8F\xE1\xBD{\xC0/|\xABd\xA8\x17\xFC\xCA]{\xBA\xE0!\xE5r.o.\x86\xD8\x95s\xDA\xAC\eS\xB9_?\xD7\x19\r%O\xE1ccQ\x8B\vd?\xADC\xB8\xA5\x1C\\4\xB3\xAE\x00\xA0c\xC5\xF6\x7F\vYhxs\xA6\x8C\x18\xA9\x02m\xAF\xC3\x19\x01.\xB8\x10\xE3\xC6\xCC@\xB4i\xA3F3i\x87n\xC4\xBB\x17\xA6\xF3\xE8\xDD\xADs\xBC{/!\xB5\xFDfQ\f\xBDT\xB3\xE1m_\x1C\xBC#s\xD1\t\x03\x89\x14\xD2\x10\xB9d\xC3*\xD0\xA1\x96J\xBC\xE1\xD4\x1A[\xC7\xA0\xC0\xC1cx\x0FD702\x96\x802#\x95\xA1w\xBA\x13\xD2\x97s\xE2]%\xC9j\r\xC39`\xA4\xB4\xB0iBB\t\xE9\xD8\b\xBC3 \xB3X"\xA7\xAA\xEB\xC4\xE1\xE6a\x83\xC5\xD2\x96\xDF\xD9\xD0O\xAD\xD7\x02\x03\x01\x00\x01\xA3\x81\xFC0\x81\xF90\x1D\x06\x03U\x1D\x0E\x04\x16\x04\x14\xB3\x112\xC9\x92\x98\x84\xE2\xC9\xF8\xD0;n\x03B\xCA\x1F\x0E\x8E<0\x81\xC9\x06\x03U\x1D#\x04\x81\xC10\x81\xBE\x80\x14'\x8Eg\x11t\xC3&\x1D?\xED3c\xB3\xA4\xD8\x1D0\xE5\xE8\xD5\xA1\x81\x9A\xA4\x81\x970\x81\x941\v0\t\x06\x03U\x04\x06\x13\x02US1\x100\x0E\x06\x03U\x04\b\f\aMontana1\x100\x0E\x06\x03U\x04\a\f\aBozeman1\x110\x0F\x06\x03U\x04\n\f\bSawtooth1\x130\x11\x06\x03U\x04\v\f\nConsulting1\x180\x16\x06\x03U\x04\x03\f\x0Fwww.wolfssl.com1\x1F0\x1D\x06\t*\x86H\x86\xF7\r\x01\t\x01\x16\x10info@wolfssl.com\x82\t\x00\x86\xFF\xF5\x8E\x10\xDE\xB8\xFB0\f\x06\x03U\x1D\x13\x04\x050\x03\x01\x01\xFF0\r\x06\t*\x86H\x86\xF7\r\x01\x01\v\x05\x00\x03\x82\x01\x01\x00\xB4T`\xAD\xA0\x032\xDE\x02\x7F!J\x81\xC6\xED\xCD\xCD\xD8\x12\x8A\xC0\xBA\x82[u\xADT\xE3|\x80j\xAC.l N\xBEM\x82\xA7G\x13\\\xF4\xC6j+\x10\x99X\xDE\xABk|"\x05\xC1\x83\x9D\xCB\xFF<\xE4-Wj\xA6\x96\xDF\xD3\xC1h\xE3\xD2\xC6\x83K\x97\xE2\xC62\x0E\xBE\xC4\x03\xB9\a\x8A[\xB8\x84\xBA\xC59?\x1CX\xA7U\xD7\xF0\x9B\xE8\xD2E\xB9\xE3\x83.\xEE\xB6qV\xB9:\xEE?'\xD8w\xE8\xFBDHe'GL\xFB\xFEr\xC3\xAC\x05{\x1D\xCB\xEB^e\x9A\xAB\x02\xE4\x88[;\x8B\v\xC7\xCC\xA9\xA6\x8B\xE1\x87\xB0\x19\x1A\f(Xo\x99R~\xED\xB0:h;\x8C\n\btr\xAB\xB9\t\xC5\xED\x04~o\v\x1C\t!\xD0\xCD\x7F\xF9\xC4^' \xE4\x85sR\x05\xD2\xBA\xF8\xD5\x8FA\xCC#.\x12m\xBC1\x98\xE7c\xA3\x8E&\xCD\xE8+\x88\xEE\xE2\xFE:tR4\x0E\xFD\x12\xE5^iP 14\xE41\xF1\xE7\xE4[\x03\x13\xDA\xACAl\xE7\xCF+"}, 1196, 0) = 1196
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool16 EVIO : Entering TLS::recv(0x7f023c001b98, 5) [(WOLFSSL*)0x7f023c0018d0, FD:0x560b46510c80]
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool16 SYSTEM : recv(15, 0x7f023c001b98, 5, 0) = -1: EAGAIN (Resource temporarily unavailable)
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool10 TLS : Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = 5).
ThreadPool16 TLS : <continued> -1 (WOLFSSL_ERROR_WANT_READ: non-blocking socket wants data to be read)
ThreadPool10 TLS : Entering TLS::do_handshake()
ThreadPool16 TLS : wolfSSL_want_read((WOLFSSL*)0x7f023c0018d0) returned true.In other words: waste of CPU time...
This is basically the result of the write thread starting the handshake (writing to the fd), causing
data being sent by the server, causing the fd becoming readable, WITHOUT that this is communicated
by a (handshake) WANT_READ: because wolfSSL_connect doesn't return.
Subsequently my read thread sees that there is something to read on the fd, but is not allowed to
call wolfSSL_connect (because the other thread is inside it) and neither can stop monitoring the fd
for readability (as explained in the comments).
After literally weeks of work, I finally managed to integrate wolfssl into libevio.
But it was really painful to deal with the duality of wolfssl_connect
which, even when called when it says it WANT_WRITE - happily continuous
to read after writing.
Here is some of the "code" that I wrote (more comment than code, but
otherwise nobody would understand what is going on 
...
// Bits of TLS::m_session_state
// _ post_handshake
// / _ want_write
// |/ _ inside_do_handshake
// || /
// || | Required action Possible transitions to Condition result
// || |
// 00x0 stop 00x0, 00x1, 01x0, 10x0 WasTrue
// 00x1 stop 00x0, 01x0, 10x0 WasTrue
// 01x0 do not stop 01x0 False
// 01x1 stop 00x0, 01x0, 10x0 WasTrue
// 10x0 stop if 10x0 obuffer->StreamBufConsumer::nothing_to_get() (False or WasTrue)
// 10x1 not possible
// 11x0 not possbile
// 11x1 not possible
//
// If the post_handshake bit is not set, then it was never set before.
// Therefore, since in the immediate past is_blocked_or_handshake_finished()
// returned true, the inside_do_handshake bit must have been set.
// Hence, if we see that neither post_handshake nor inside_do_handshake
// are set then the read thread returned from do_handshake and
// signalled if it wants to continue with reading or writing by clearing
// or setting the want_write bit; however, since we also get here when
// state == 0, it is possible that in that case it was THIS thread that
// just reset the inside_do_handshake bit (after having just executed
// do_handshake). In that case the read thread is still running and
// could cause transitions from 00x0 to any other state, but that doesn't
// change the fact that the required action to stop is a WasTrue.
//
// Hence, if we see that handshake_wants_write_and_not_blocked(state)
// then the read thread must have left do_handshake (resetting
// inside_do_handshake) and set the want_write bit. That means the
// handshake is not finished yet and the handshake wants to continue
// with writing (not reading!).
// Therefore the *read* thread will not re-enter do_handshake and
// thus m_session_state can't change anymore.
//
// Therefore this condition must return fuzzy::WasTrue for all states
// except where handshake_wants_write(state), in which case it should
// return fuzzy::False.
//
// If is_post_handshake(state) then instead it should return
// obuffer->StreamBufConsumer::nothing_to_get(). Note that a state of
// post_handshake can also no longer change, leaving the fuzzy::False
// returned by StreamBufConsumer::nothing_to_get() at fuzzy::False.
utils::FuzzyBool must_stop_output_device(OutputBuffer const* obuffer)
{
int state = m_session_state.load(std::memory_order_relaxed);
if (handshake_wants_write_and_not_blocked(state))
return fuzzy::False;
utils::FuzzyBool output_buffer_is_empty = obuffer->StreamBufConsumer::nothing_to_get();
if (output_buffer_is_empty.is_false())
m_session_state.fetch_or(s_have_plain_text, std::memory_order_release);
if (is_post_handshake(state))
return output_buffer_is_empty;
return fuzzy::WasTrue;
}
// Bits of TLS::m_session_state
// _ post_handshake
// / _ want_write
// |/ _ inside_do_handshake
// || /
// || | Required action Possible transitions to Condition result
// || |
// 00x0 do not stop 00x0 False
// 00x1 stop 00x0, 01x0, 10x0 WasTrue
// 01x0 do not stop 00x0, 01x0, 01x1, 10x0 False
// 01x1 do not stop 00x0, 01x0, 10x0 False
// 10x0 do not stop 10x0 False
// 10x1 not possible
// 11x0 not possbile
// 11x1 not possible
//
// We can not stop the input device when the state is 01x0 because
// that means that the write thread is running which might stop
// the output device (and stopping both input and output device
// could terminate the application; or more specifically it means
// that 'we are done' with this device in evio terms - which is
// obviously not true).
//
// Because that state (01x0) can transition to 01x1 (when the
// write thread enters do_handshake()), that state can not cause
// us to stop the input device either or the result of state 01x0
// would need WasFalse to be returned - which is not allowed (or
// rather, that can't work: due to a race condition we could
// *miss* stopping on state 01x1).
//
// Obviously we do not want to stop the input device when the
// state is 00x0 or 10x0; in the first case because the handshake
// is not finished and it wants to read, and in the second because
// the handshake is finished and we can return to the sane strategy
// of never stopping to read an input device until we're done with it.
//
// We HAVE to stop when the state is 00x1 because reading is
// required but the write thread is handling the handshake at
// the moment (so we can't). Not stopping could lead to an immediate
// return to read_from_fd and thus cause a tight loop using 100% cpu.
//
// None of the other states can transition to 00x1, so that we
// can return fuzzy::False for all of them as is required (see above).
//
// The reason that a transition to 00x1 is not possible is because
// 1) when the write thread is inside do_handshake (xxx1) the only
// possible transition is when the write thread leaves do_handshake
// which always resets the least significant bit (xxx1 --> xxx0).
// 2) Once the state is 10x0 the handshake is finished and the state
// won't return to an unfinished handshake.
// 3) If the write thread is outside do_handshake and the state is
// 01x0 then the only possible (first) transition is to 01x1 (
// which subsequently could change back to 01x1, to 10x0 or to
// 00x0, and)
// 4) If the write thread is outside do_handshake and the state is
// 00x0 then the write thread is stopped, so it won't make any
// additional changes anymore.
//
// Not stopping in the state 01x1 is unfortunate, but discussed
// elsewhere.
utils::FuzzyBool must_stop_input_device() const
{
int state = m_session_state.load(std::memory_order_relaxed);
return handshake_wants_read_and_blocked(state) ? fuzzy::WasTrue : fuzzy::False;
}and....
// Did the handshake finish successfully?
if (TLS::handshake_completed(state))
{
Dout(dc::tls, "Handshake completed!");
m_connected_flags |= is_connected;
// Do the m_connected() callback at this point (as opposed to when the TCP connection was established),
// as in most cases it will be used as a "you can now send/receive data" signal...
if (m_connected)
{
int count = allow_deletion_count;
m_connected(allow_deletion_count, true);
if (allow_deletion_count > count)
// Device is marked for deletion.
return;
}
// It is impossible to test if the output buffer is empty from this thread.
//
// It would work to simply start the output device and let the write thread deal with it (that is,
// the write thread would stop the output device again if the buffer turns out to be empty).
// However, if there is a way to avoid a needless start and subsequent stop then that would be preferable.
//
// If we do some fuzzy test - and based on that start the output device, then
// nothing is lost. The only thing that we want to avoid is that we end up with
// a stopped output device while there is something in the output buffer.
// It is not possible however that by doing nothing we end in that state unless
// there is already something in the output buffer (that was flushed) and no
// new flush happens after this point (from another thread).
//
// When something is, or was, written to the output buffer and flushed - then that
// caused the output device to be started. So, it is necessary that subsequently
// this was ignored from write_to_fd() because the TLS handshake had not finished
// yet.
//
// Moreover, the output device begins started, so it must have been stopped in
// the meantime (as part of the TLS handshake), which happens exclusively from
// the write thread.
//
// Therefore, it is possible to know if there is something in the (plain text)
// output buffer as detected by the write thread when it stopped the output
// device.
if (m_tls.need_start_output_device(state))
start_output_device(state_t::wat(m_state));
// It is very unlikely that there is more to read, immediately after the handshake.
break;
}
// Stopping the input device could cause the application to exit if
// this is the only device and the output device is stopped too.
// Therefore, we will only stop the input device if
// 1) the handshake is not finished,
// 2) the handshake wants to read,
// 3) the write thread is inside do_handshake.
// See TLS::must_stop_input_device for the detailed argumentation.
utils::FuzzyCondition condition_must_stop_input_device([this]{
return m_tls.must_stop_input_device();
});
if (condition_must_stop_input_device.is_momentary_false())
{
Dout(dc::tls, "Trying buffer again because condition_must_stop_input_device.is_momentary_false() returned true (state = " << state << ").");
continue;
}I suspect nobody actually read all that, but you get the idea.
Also - I need to know the negotiated size. But there is no way to access that 
(ssl->max_fragment can not be accessed because 'struct WOLFSSL' is only declared, not defined).
As also stated on https://www.wolfssl.com/using-maximum-f … h-wolfssl/
the maximum fragment length is 2^14 = 0x4000 = 16384 bytes.
When configured with --enable-maxfragment the wolfSSL client sends something with
the client HELLO message to the server, which responds with the actual frag length
to be used (am I correct?).
In the source I find the following:
int TLSX_UseMaxFragment(TLSX** extensions, byte mfl, void* heap)
{
...
if (extensions == NULL || mfl < WOLFSSL_MFL_MIN || mfl > WOLFSSL_MFL_MAX)
return BAD_FUNC_ARG;
...where
/* Fragment lengths */
enum {
WOLFSSL_MFL_2_9 = 1, /* 512 bytes */
WOLFSSL_MFL_2_10 = 2, /* 1024 bytes */
WOLFSSL_MFL_2_11 = 3, /* 2048 bytes */
WOLFSSL_MFL_2_12 = 4, /* 4096 bytes */
WOLFSSL_MFL_2_13 = 5, /* 8192 bytes *//* wolfSSL ONLY!!! */
WOLFSSL_MFL_2_8 = 6, /* 256 bytes *//* wolfSSL ONLY!!! */
WOLFSSL_MFL_MIN = WOLFSSL_MFL_2_9,
WOLFSSL_MFL_MAX = WOLFSSL_MFL_2_8,
};In other words, you are only allowed to pass for mfl: 1, 2, 3, 4, 5 or 6 with
the meanings: 512, 1024, 2048, 4096, 8192 and 256 bytes.
There is no 16384 bytes.
Also, the server reply is decoded by TLSX_MFL_Parse :
static int TLSX_MFL_Parse(WOLFSSL* ssl, byte* input, word16 length,
byte isRequest)
{
...
switch (*input) {
case WOLFSSL_MFL_2_8 : ssl->max_fragment = 256; break;
case WOLFSSL_MFL_2_9 : ssl->max_fragment = 512; break;
case WOLFSSL_MFL_2_10: ssl->max_fragment = 1024; break;
case WOLFSSL_MFL_2_11: ssl->max_fragment = 2048; break;
case WOLFSSL_MFL_2_12: ssl->max_fragment = 4096; break;
case WOLFSSL_MFL_2_13: ssl->max_fragment = 8192; break;
default:
SendAlert(ssl, alert_fatal, illegal_parameter);
return UNKNOWN_MAX_FRAG_LEN_E;
}
...again restricting the possible fragment size to a maximum of 8192 bytes.
What happened to the (allowed) value of 16384?
Hi Kaleb,
my remarks were exclusively about wolfSSL_connect, aka - the handshake. I already know that I'm not allowed to call that concurrently. It still poses the problem as stated, since I can't use a mutex.
Thanks for pointing me to `wolfSSL_write_dup` again, I will surely use that post-handshake even though that means I will have to include wolfSSL into my project because of the non-default configuration that it requires.
In the mean time I intercepted the actual reads and writes from/to the socket for more debug output!
So we can better see what is going on (just for fun):
daniel:~/projects/aicxx/ai-evio-testsuite/ai-evio-testsuite/src>tls_socket | egrep ' TLS '
WARNING : core size is limited (hard limit: 0 kb). Core dumps might be truncated!
ThreadPool20 TLS : Entering TLS::session_init("localhost")
ThreadPool20 TLS : wolfSSL_new(0x55d9f66c9120) = 0x7f87bc0018d0
ThreadPool20 TLS : wolfSSL_connect((WOLFSSL*)0x7f87bc0018d0) = <unfinished>
ThreadPool20 TLS : send(15, "\x16\x03\x03\x01;\x01\x00\x017\x03\x03\xBA\xE8\xE5\x11VD\x8B\xC0\xDE\xE9\t\xFC\xB8\xEAl\xFE28\xF1\x14\xA4\xED\xA5c\x97\xFA-\xED\xD5j\xCB\xAB\x00\x00X\x13\x01\x13\x02\x13\x03\x13\x04\x13\x05\xC0\xB4\xC0\xB5\xC0,\xC0+\xC00\xC0/\x00\x9F\x00\x9E\xCC\xA9\xCC\xA8\xCC\xAA\xC0'\xC0#\xC0(\xC0$\xC0\n\xC0\t\xC0\a\xC0\b\xC0\x14\xC0\x13\xC0\x11\xC0\x12\xC0\xAC\xC0\xAE\xC0\xAF\x00k\x00g\x009\x003\x00\x16\xCC\x14\xCC\x13\xCC\x15\xC0\x06\x00E\x00\x88\x00\xBE\x00\xC4\x01\x00\x00\xB6\x003\x00G\x00E\x00\x17\x00A\x04\x1F\xFDy'd\xA8;\xEA$\xE8\x1A\x06}\x8E\xF6\xCEYS\x183<\t\x99\xF2E\xA4t\x1F\x7FV<\rM\xCAv\xC6|]Z\xC6@Sl\xD8\e\xFEo\x9E(\xE91\xBF!\xBF\b\xDD\x13\xD9\xB7\xEA1\xD4\xBF(\x00+\x00\t\b\x03\x04\x03\x03\x03\x02\x03\x01\x00\r\x00\"\x00 \x06\x03\x05\x03\x04\x03\x02\x03\b\a\b\x06\b\v\b\x05\b\n\b\x04\b\t\x06\x01\x05\x01\x04\x01\x03\x01\x02\x01\x00\v\x00\x02\x01\x00\x00\n\x00&\x00$\x00\x19\x00\x1C\x00\x18\x00\e\x00\x1E\x00\x17\x00\x16\x00\x1A\x00\x1D\x00\x15\x00\x14\x00\x13\x00\x12\x00\x10\x00\x11\x00\x0F\x01\x01\x01\x00\x00\x16\x00\x00\x00\x17\x00\x00", 320, 0) = 320
ThreadPool20 TLS : recv(15, 0x7f87bc001b90, 5, 0) = -1
ThreadPool20 TLS : <continued> -1 (WOLFSSL_ERROR_WANT_READ: non-blocking socket wants data to be read)
ThreadPool20 TLS : wolfSSL_want_read((WOLFSSL*)0x7f87bc0018d0) returned true.
ThreadPool20 TLS : Set m_session_state to session_state (handshake_want_read).
ThreadPool20 TLS : m_session_state == handshake_want_read
ThreadPool20 TLS : wolfSSL_connect((WOLFSSL*)0x7f87bc0018d0) = <unfinished>
ThreadPool20 TLS : recv(15, {"\x16\x03\x03\x00Z"}, 5, 0) = 5
ThreadPool20 TLS : recv(15, {"\x02\x00\x00V\x03\x03\xB9\xE7\\\xAC\xBB\x82\x97\xB0\x05\x81\x06\xAD\x11\xF3\xCFl\x93\x90\xA1\xA6\a\x95\xDC\xB1\xC92\x81\x03\xCE\x8C\xB7\xA6 \xE5\xCF\xC1\x1E\x97.\xFB.\xAA@9W\xD1S\x968dKjL\xF5<\x84\x98\\\x88\xD5\xAC\xE3`Y\x0F\xC00\x00\x00\x0E\x00\x16\x00\x00\x00\v\x00\x02\x01\x00\x00\x17\x00\x00"}, 90, 0) = 90
ThreadPool20 TLS : recv(15, 0x7f87bc001b90, 5, 0) = -1
ThreadPool20 TLS : <continued> -1 (WOLFSSL_ERROR_WANT_READ: non-blocking socket wants data to be read)
ThreadPool20 TLS : wolfSSL_want_read((WOLFSSL*)0x7f87bc0018d0) returned true.
ThreadPool20 TLS : m_session_state == handshake_want_read
ThreadPool20 TLS : wolfSSL_connect((WOLFSSL*)0x7f87bc0018d0) = <unfinished>
ThreadPool20 TLS : recv(15, {"\x16\x03\x03\x04\xAC"}, 5, 0) = 5
ThreadPool20 TLS : recv(15, {"\v\x00\x04\xA8\x00\x04\xA5\x00\x04\xA20\x82\x04\x9E0\x82\x03\x86\xA0\x03\x02\x01\x02\x02\x01\x010\r\x06\t*\x86H\x86\xF7\r\x01\x01\v\x05\x000\x81\x941\v0\t\x06\x03U\x04\x06\x13\x02US1\x100\x0E\x06\x03U\x04\b\f\aMontana1\x100\x0E\x06\x03U\x04\a\f\aBozeman1\x110\x0F\x06\x03U\x04\n\f\bSawtooth1\x130\x11\x06\x03U\x04\v\f\nConsulting1\x180\x16\x06\x03U\x04\x03\f\x0Fwww.wolfssl.com1\x1F0\x1D\x06\t*\x86H\x86\xF7\r\x01\t\x01\x16\x10info@wolfssl.com0\x1E\x17\r180413152310Z\x17\r210107152310Z0\x81\x901\v0\t\x06\x03U\x04\x06\x13\x02US1\x100\x0E\x06\x03U\x04\b\f\aMontana1\x100\x0E\x06\x03U\x04\a\f\aBozeman1\x100\x0E\x06\x03U\x04\n\f\awolfSSL1\x100\x0E\x06\x03U\x04\v\f\aSupport1\x180\x16\x06\x03U\x04\x03\f\x0Fwww.wolfssl.com1\x1F0\x1D\x06\t*\x86H\x86\xF7\r\x01\t\x01\x16\x10info@wolfssl.com0\x82\x01\"0\r\x06\t*\x86H\x86\xF7\r\x01\x01\x01\x05\x00\x03\x82\x01\x0F\x000\x82\x01\n\x02\x82\x01\x01\x00\xC0\x95\b\xE1WA\xF2qm\xB7\xD2EA'\x01e\xC6E\xAE\xF2\xBC$0\xB8\x95\xCE/N\xD6\xF6\x1C\x88\xBC|\x9F\xFB\xA8g\x7F\xFE\\\x9CQu\xF7\x8A\xCA\a\xE75/\x8F\xE1\xBD{\xC0/|\xABd\xA8\x17\xFC\xCA]{\xBA\xE0!\xE5r.o.\x86\xD8\x95s\xDA\xAC\eS\xB9_?\xD7\x19\r%O\xE1ccQ\x8B\vd?\xADC\xB8\xA5\x1C\\4\xB3\xAE\x00\xA0c\xC5\xF6\x7F\vYhxs\xA6\x8C\x18\xA9\x02m\xAF\xC3\x19\x01.\xB8\x10\xE3\xC6\xCC@\xB4i\xA3F3i\x87n\xC4\xBB\x17\xA6\xF3\xE8\xDD\xADs\xBC{/!\xB5\xFDfQ\f\xBDT\xB3\xE1m_\x1C\xBC#s\xD1\t\x03\x89\x14\xD2\x10\xB9d\xC3*\xD0\xA1\x96J\xBC\xE1\xD4\x1A[\xC7\xA0\xC0\xC1cx\x0FD702\x96\x802#\x95\xA1w\xBA\x13\xD2\x97s\xE2]%\xC9j\r\xC39`\xA4\xB4\xB0iBB\t\xE9\xD8\b\xBC3 \xB3X\"\xA7\xAA\xEB\xC4\xE1\xE6a\x83\xC5\xD2\x96\xDF\xD9\xD0O\xAD\xD7\x02\x03\x01\x00\x01\xA3\x81\xFC0\x81\xF90\x1D\x06\x03U\x1D\x0E\x04\x16\x04\x14\xB3\x112\xC9\x92\x98\x84\xE2\xC9\xF8\xD0;n\x03B\xCA\x1F\x0E\x8E<0\x81\xC9\x06\x03U\x1D#\x04\x81\xC10\x81\xBE\x80\x14'\x8Eg\x11t\xC3&\x1D?\xED3c\xB3\xA4\xD8\x1D0\xE5\xE8\xD5\xA1\x81\x9A\xA4\x81\x970\x81\x941\v0\t\x06\x03U\x04\x06\x13\x02US1\x100\x0E\x06\x03U\x04\b\f\aMontana1\x100\x0E\x06\x03U\x04\a\f\aBozeman1\x110\x0F\x06\x03U\x04\n\f\bSawtooth1\x130\x11\x06\x03U\x04\v\f\nConsulting1\x180\x16\x06\x03U\x04\x03\f\x0Fwww.wolfssl.com1\x1F0\x1D\x06\t*\x86H\x86\xF7\r\x01\t\x01\x16\x10info@wolfssl.com\x82\t\x00\x86\xFF\xF5\x8E\x10\xDE\xB8\xFB0\f\x06\x03U\x1D\x13\x04\x050\x03\x01\x01\xFF0\r\x06\t*\x86H\x86\xF7\r\x01\x01\v\x05\x00\x03\x82\x01\x01\x00\xB4T`\xAD\xA0\x032\xDE\x02\x7F!J\x81\xC6\xED\xCD\xCD\xD8\x12\x8A\xC0\xBA\x82[u\xADT\xE3|\x80j\xAC.l N\xBEM\x82\xA7G\x13\\\xF4\xC6j+\x10\x99X\xDE\xABk|\"\x05\xC1\x83\x9D\xCB\xFF<\xE4-Wj\xA6\x96\xDF\xD3\xC1h\xE3\xD2\xC6\x83K\x97\xE2\xC62\x0E\xBE\xC4\x03\xB9\a\x8A[\xB8\x84\xBA\xC59?\x1CX\xA7U\xD7\xF0\x9B\xE8\xD2E\xB9\xE3\x83.\xEE\xB6qV\xB9:\xEE?'\xD8w\xE8\xFBDHe'GL\xFB\xFEr\xC3\xAC\x05{\x1D\xCB\xEB^e\x9A\xAB\x02\xE4\x88[;\x8B\v\xC7\xCC\xA9\xA6\x8B\xE1\x87\xB0\x19\x1A\f(Xo\x99R~\xED\xB0:h;\x8C\n\btr\xAB\xB9\t\xC5\xED\x04~o\v\x1C\t!\xD0\xCD\x7F\xF9\xC4^' \xE4\x85sR\x05\xD2\xBA\xF8\xD5\x8FA\xCC#.\x12m\xBC1\x98\xE7c\xA3\x8E&\xCD\xE8+\x88\xEE\xE2\xFE:tR4\x0E\xFD\x12\xE5^iP 14\xE41\xF1\xE7\xE4[\x03\x13\xDA\xACAl\xE7\xCF+"}, 1196, 0) = 1196
ThreadPool20 TLS : recv(15, 0x7f87bc001b90, 5, 0) = -1
ThreadPool20 TLS : <continued> -1 (WOLFSSL_ERROR_WANT_READ: non-blocking socket wants data to be read)
ThreadPool20 TLS : wolfSSL_want_read((WOLFSSL*)0x7f87bc0018d0) returned true.
ThreadPool20 TLS : m_session_state == handshake_want_read
ThreadPool20 TLS : wolfSSL_connect((WOLFSSL*)0x7f87bc0018d0) = <unfinished>
ThreadPool20 TLS : recv(15, {"\x16\x03\x03\x01M"}, 5, 0) = 5
ThreadPool20 TLS : recv(15, {"\f\x00\x01I\x03\x00\x17A\x04;D\xFB\x84\xB0\xAA\xCFj\x88]\xC4U\xBA`\xEFf\xEBe\xB5\x04\xCB.\xC0\x10i\agH'\xF2Ep\xB1k\xEF\xA8\nGU\xBF\xF6\xB5\x97B\xDF\\\xE3\xF3G\x8D\xD4S\x0E\xD5\x9F\xC2\x94o\xDC\n)\xEA\xF7\xD4\b\x06\x01\x00fI\x02\xD8\v\x17\xC5R\xF7\xFC+\x8E\xCE\tk\xF8}=\x94\xB1\a\xF6\xAB{\xB8,\xDE\xF4\x16\xA4\xD0&\\w\xE2]\x19\xDAdV\xE2\x04P\xCD\x97\xE5\xA6\xDD\x98<\xA1a\xCD\e(?6\xF6\x98\x06\xBC2\e\xFA[\xDB~\rF\xAD]\xBC\xA7\xC7\xEA\xD9\x84\xB3\x8Ec\xE08\xF7j\xCF\bq\x83\x9A\x86\xC0\xA4y,\rW:\xC3\xA4\xBA84\x94\xDA\x157{\xAE\x83\x86^\xF6\xE8\xF7\xFD\x1E\x14\x89d\x0E[\xF7\xCD\xCD\f\xCE\xD3@;\xE3`O\xE1!\xEB\x17\xF4\xE0\xBCk\xDD\xBE^e\x1E\\\xF8)\xE9\xF2(g\xD4B\xD7\v\x96\xBA\xDB\xFD\xEFe\xF4\x89\xB8c\xA5\x8A\xDB\xAFZf\xAFV0.\xFD\x11r\xFB@\xBE\xB0\e\xF7\x1711\x99v\xE7a\x9B:YBHTtd\xC5\x18#h?7\xA3\xD9\xD1\xD1\xE5\xA1\xD1yn\xB5\xD0:%^\xA3\xB3\xC5\x87\x94F W\x16\xEC\xAAO\xE2\xE5\x90\xCE\nX]\xAEa\xE7z,TTD\\$\xB9W\x9D\x91K\x10\x9D"}, 333, 0) = 333
ThreadPool20 TLS : recv(15, {"\x16\x03\x03\x00\x04"}, 5, 0) = 5
ThreadPool20 TLS : recv(15, {"\x0E\x00\x00\x00"}, 4, 0) = 4
ThreadPool20 TLS : send(15, "\x16\x03\x03\x00F\x10\x00\x00BA\x04\xC7\f\x1C\x15\xF3\xE8P\xDEe\x80\xD7\xCA\x86\xEC\xA5\xDBm\xAA>\x94\xA3vA\xC85\xC7\x92\xD5}~Xv\xA0\x8D\xC4 \x06\xE0\x14p\xE1ZU\xD1\xEF\xA8\xC9\xA1\x8AUo\xE8\xF6i\x14\xAD\x87p\ra\v\xB8\xB7E", 75, 0) = 75
ThreadPool20 TLS : send(15, "\x14\x03\x03\x00\x01\x01", 6, 0) = 6
ThreadPool20 TLS : send(15, "\x16\x03\x03\x00(\xFA\xF6oy\f\x81\x94\xD7D\x9DX\x87(\xA7\xE3\x88Y\xFD\xA77\x8D{\x87\x17\x95\xD6^\x8C\xEC\x12\xB7^\xE91\"\x7F\f\xD3q*", 45, 0) = 45
ThreadPool20 TLS : recv(15, 0x7f87bc001b90, 5, 0) = -1
ThreadPool20 TLS : <continued> -1 (WOLFSSL_ERROR_WANT_READ: non-blocking socket wants data to be read)
ThreadPool20 TLS : wolfSSL_want_read((WOLFSSL*)0x7f87bc0018d0) returned true.
ThreadPool20 TLS : m_session_state == handshake_want_read
ThreadPool20 TLS : wolfSSL_connect((WOLFSSL*)0x7f87bc0018d0) = <unfinished>
ThreadPool20 TLS : recv(15, {"\x14\x03\x03\x00\x01"}, 5, 0) = 5
ThreadPool20 TLS : recv(15, {"\x01"}, 1, 0) = 1
ThreadPool20 TLS : recv(15, {"\x16\x03\x03\x00("}, 5, 0) = 5
ThreadPool20 TLS : recv(15, {"\x17\x7F\xDA\xBE\x87\v\xDA\xE1\x00\"\xA4\x8B\x9C\xB7|B\f\xAB\x19\xD7\xC2\x06;m\xB2d#p\xE8\xBAc\xCAH%\xEC\\I\xB4\xBA3"}, 40, 0) = 40
ThreadPool20 TLS : <continued> SSL_SUCCESSso you can see all send's and recv's of the handshake.
I thought this output looks rather strange: `wolfSSL_connect` exclusively returns `WOLFSSL_ERROR_WANT_READ`.
Even after the first time I already stop monitoring the fd for writability.
I suppose therefore that the following is happening:
Upon the first call to `wolfSSL_connect` it calls send() and then recv() (which obviously fails),
then when there is something to read on the fd I call `wolfSSL_connect` again which now
reads the server reply and immediately writes something back to the socket (which happens
to succeed).
I am not sure I'm happy with this behavior... This means namely that I'm writing with the wrong
thread; I am using one thread to handle a writable socket and one thread to handle a readable
socket (one at a time), so that there is always at most one thread reading and at most one
thread writing.
If my socket is readable then the "read thread" calls `wolfSSL_connect` - if that subsequently
writes to the socket then that kinda messes up my thread-safety design
I can't think how this could lead to problems currently, because if `wolfSSL_connect` returns
`WANT_READ` I stop monitoring the socket for writability, which basically should make it
impossible that the 'write thread' start running for this socket.
However, I am assuming that it can also happen the other way around:
1) `wolfSSL_connect` tries to send(), but it fails to write all the bytes that it needs to write,
probably calls send() again(?) which blocks returns EAGAIN, and returns WANT_WRITE.
2) Now I am monitoring the socket (still) for readability and writability; the socket becomes
writable again and the 'write thread' calls `wolfSSL_connect`.
3) This time `wolfSSL_connect` manages to write everything - and (assumingly) immediately
continues with a call to recv() (as it would do in the non-blocking case).
4) The socket becomes readable - now the 'read thread' calls `wolfSSL_connect` too.
Ok, at least it is clear that my program would be violating something in that case: as long
as the 'write thread' didn't return yet from `wolfSSL_connect` I am not allowed to call it
from the `read thread`. However, I can not block -ever- my threads run till there is nothing
to do.
So, this means that in this situation my `read thread` can't do anything: it can't read the socket,
because the `write thread` is still inside `wolfSSL_connect`. I can't do nothing either though:
if the thread just returns then it will *immediately* return because the fd is still readable, causing
100% CPU usage, which is even worse than blocking (on a mutex). So now I need to stop
monitoring the fd for readability and then return.
Also I will have to keep track, in a thread-safe way, if some thread is inside `wolfSSL_connect`.
I guess I'll use my std::atomic<session_state_type> variable for that, which currently only
tracks what the last return value of `wolfSSL_connect` was - but that is not enough when
`wolfSSL_connect` calls read and/or write without regard for natural epoll synchronization .
Full debug output...
daniel:~/projects/aicxx/ai-evio-testsuite/ai-evio-testsuite/src>tls_socket
WARNING : core size is limited (hard limit: 0 kb). Core dumps might be truncated!
THREADPOOL : Entering add_threads(30)
ThreadPool00 NOTICE : Thread started. Set debug margin to "ThreadPool00 ".
ThreadPool01 NOTICE : Thread started. Set debug margin to "ThreadPool01 ".
ThreadPool02 NOTICE : Thread started. Set debug margin to "ThreadPool02 ".
ThreadPool03 NOTICE : Thread started. Set debug margin to "ThreadPool03 ".
ThreadPool04 NOTICE : Thread started. Set debug margin to "ThreadPool04 ".
ThreadPool05 NOTICE : Thread started. Set debug margin to "ThreadPool05 ".
ThreadPool07 NOTICE : Thread started. Set debug margin to "ThreadPool07 ".
ThreadPool06 NOTICE : Thread started. Set debug margin to "ThreadPool06 ".
ThreadPool08 NOTICE : Thread started. Set debug margin to "ThreadPool08 ".
ThreadPool09 NOTICE : Thread started. Set debug margin to "ThreadPool09 ".
ThreadPool10 NOTICE : Thread started. Set debug margin to "ThreadPool10 ".
ThreadPool11 NOTICE : Thread started. Set debug margin to "ThreadPool11 ".
ThreadPool12 NOTICE : Thread started. Set debug margin to "ThreadPool12 ".
ThreadPool13 NOTICE : Thread started. Set debug margin to "ThreadPool13 ".
ThreadPool14 NOTICE : Thread started. Set debug margin to "ThreadPool14 ".
ThreadPool15 NOTICE : Thread started. Set debug margin to "ThreadPool15 ".
ThreadPool16 NOTICE : Thread started. Set debug margin to "ThreadPool16 ".
ThreadPool17 NOTICE : Thread started. Set debug margin to "ThreadPool17 ".
ThreadPool19 NOTICE : Thread started. Set debug margin to "ThreadPool19 ".
ThreadPool18 NOTICE : Thread started. Set debug margin to "ThreadPool18 ".
ThreadPool20 NOTICE : Thread started. Set debug margin to "ThreadPool20 ".
ThreadPool21 NOTICE : Thread started. Set debug margin to "ThreadPool21 ".
ThreadPool22 NOTICE : Thread started. Set debug margin to "ThreadPool22 ".
ThreadPool23 NOTICE : Thread started. Set debug margin to "ThreadPool23 ".
ThreadPool24 NOTICE : Thread started. Set debug margin to "ThreadPool24 ".
ThreadPool25 NOTICE : Thread started. Set debug margin to "ThreadPool25 ".
ThreadPool26 NOTICE : Thread started. Set debug margin to "ThreadPool26 ".
ThreadPool27 NOTICE : Thread started. Set debug margin to "ThreadPool27 ".
ThreadPool29 NOTICE : Thread started. Set debug margin to "ThreadPool29 ".
THREADPOOL : Entering AIThreadPool::new_queue(16, 1)
ThreadPool28 NOTICE : Thread started. Set debug margin to "ThreadPool28 ".
THREADPOOL : Returning index #0; size is now 1 for utils::Vector<AIThreadPool::PriorityQueue, utils::VectorIndex<ordering_category::QueueHandle>, std::allocator<AIThreadPool::PriorityQueue> > at 0x7ffeacb27578
ThreadPool06 THREADPOOL : Beginning of thread pool main loop (q = #0)
ThreadPool08 THREADPOOL : Beginning of thread pool main loop (q = #0)
ThreadPool24 THREADPOOL : Beginning of thread pool main loop (q = #0)
ThreadPool07 THREADPOOL : Beginning of thread pool main loop (q = #0)
ThreadPool22 THREADPOOL : Beginning of thread pool main loop (q = #0)
ThreadPool27 THREADPOOL : Beginning of thread pool main loop (q = #0)
ThreadPool17 THREADPOOL : Beginning of thread pool main loop (q = #0)
ThreadPool11 THREADPOOL : Beginning of thread pool main loop (q = #0)
ThreadPool20 THREADPOOL : Beginning of thread pool main loop (q = #0)
ThreadPool05 THREADPOOL : Beginning of thread pool main loop (q = #0)
ThreadPool28 THREADPOOL : Beginning of thread pool main loop (q = #0)
ThreadPool12 THREADPOOL : Beginning of thread pool main loop (q = #0)
ThreadPool01 THREADPOOL : Beginning of thread pool main loop (q = #0)
EVIO : Entering EventLoop::EventLoop(#0)
EVIO : Entering EventLoopThread::init(#0)
ThreadPool16 THREADPOOL : Beginning of thread pool main loop (q = #0)
ThreadPool02 THREADPOOL : Beginning of thread pool main loop (q = #0)
ThreadPool04 THREADPOOL : Beginning of thread pool main loop (q = #0)
ThreadPool00 THREADPOOL : Beginning of thread pool main loop (q = #0)
ThreadPool23 THREADPOOL : Beginning of thread pool main loop (q = #0)
ThreadPool21 THREADPOOL : Beginning of thread pool main loop (q = #0)
ThreadPool03 THREADPOOL : Beginning of thread pool main loop (q = #0)
ThreadPool13 THREADPOOL : Beginning of thread pool main loop (q = #0)
ThreadPool18 THREADPOOL : Beginning of thread pool main loop (q = #0)
ThreadPool10 THREADPOOL : Beginning of thread pool main loop (q = #0)
ThreadPool09 THREADPOOL : Beginning of thread pool main loop (q = #0)
ThreadPool15 THREADPOOL : Beginning of thread pool main loop (q = #0)
ThreadPool26 THREADPOOL : Beginning of thread pool main loop (q = #0)
ThreadPool25 THREADPOOL : Beginning of thread pool main loop (q = #0)
ThreadPool29 THREADPOOL : Beginning of thread pool main loop (q = #0)
ThreadPool19 THREADPOOL : Beginning of thread pool main loop (q = #0)
ThreadPool14 THREADPOOL : Beginning of thread pool main loop (q = #0)
EventLoopThr NOTICE : Thread started. Set debug margin to "EventLoopThr ".
EventLoopThr EVIO : Entering EventLoopThread::emain() [no indentation]
EventLoopThr SYSTEM : epoll_create1(EPOLL_CLOEXEC) = 14
EventLoopThr NOTICE : Entering Signals::unblock(sigmask, 34, 0x55a873a79ae0)
EventLoopThr NOTICE : Entering Signals::register_callback(34, 0x55a873a79ae0)
EventLoopThr SYSTEM : epoll_pwait() = <unfinished>
EVIO : Entering evio::create<evio::TLSSocket>()
EVIO : Entering InputDevice::InputDevice() [FD:0x55a875899140]
EVIO : Entering OutputDevice::OutputDevice() [FD:0x55a875899140]
EVIO : Entering Socket::Socket() [FD:0x55a875899140]
TLS : Entering TLS::TLS() [0x55a8758990a0]
TLS : Entering evio::protocol::TLS::global_tls_initialization()
TLS : wolfSSL_Init() = SSL_SUCCESS
TLS : wolfSSL_CTX_new(wolfTLS_client_method()) = 0x55a875899270
TLS : wolfSSL_CTX_SetMinVersion(0x55a875899270, WOLFSSL_TLSV1_2) = SSL_SUCCESS
TLS : wolfSSL_CTX_load_verify_locations(s_context, "/etc/ssl/cert.pem", NULL) = SSL_SUCCESS
TLS : wolfSSL_CTX_load_verify_locations(s_context, "/usr/src/AUR/wolfssl/wolfssl-examples-git/certs/ca-cert.pem", NULL) = SSL_SUCCESS
EVIO : Returning device pointer 0x55a875898fc0 [FD:0x55a875899140].
EVIO : Entering OutputDevice::set_source<>(0x7ffeacb27320) [FD:0x55a875899140]
EVIO : Entering OutputStream::create_buffer(FD:0x55a875899140, 1048320, 18446744073709551615)
IO : Entering StreamBuf(131040, 1048320, 18446744073709551615) [0x55a8758d64c0]
EVIO : StreamBufProducer::create: allocating new memory block of size 131040
EVIO : Entering InputDevice::set_sink<>(0x7ffeacb272b8) [FD:0x55a875899140]
EVIO : Entering InputDecoder::create_buffer(FD:0x55a875899140, 65280, 18446744073709551615)
IO : Entering StreamBuf(8160, 65280, 18446744073709551615) [0x55a8758d6590]
EVIO : StreamBufProducer::create: allocating new memory block of size 8160
EVIO : Entering TLS::set_device(FD:0x55a875899140, FD:0x55a875899140)
EVIO : Entering Socket::connect(127.0.0.1:11111, 0, 0, AF_UNSPEC) [FD:0x55a875899140]
SYSTEM : socket(2, SOCK_STREAM | SOCK_NONBLOCK | SOCK_CLOEXEC, 0) = 15
NOTICE : Setting receive buffer size for socket 15 to 8160 bytes.
SYSTEM : setsockopt(15, SOL_SOCKET, SO_RCVBUF, {8160}, 4) = 0
NOTICE : Setting send buffer size for socket 15 to 131040 bytes.
SYSTEM : setsockopt(15, SOL_SOCKET, SO_SNDBUF, {131040}, 4) = 0
SYSTEM : connect(15, 127.0.0.1:11111, 16) = -1: EINPROGRESS (Operation now in progress)
EVIO : Entering FileDescriptor::init(15) [FD:0x55a875899140]
EVIO : Entering InputDevice::init_input_device() [FD:0x55a875899140]
IO : Entering OutputDevice::init_output_device() [FD:0x55a875899140]
EVIO : Entering InputDevice::start_input_device({{m_flags:FDS_RW|FDS_R_OPEN|FDS_W_OPEN|FDS_SAME, m_epoll_event:{events:, data:FD:0x55a875899140}}}) [FD:0x55a875899140]
EVIO : Entering EventLoopThread::start({m_flags:FDS_RW|FDS_R_OPEN|FDS_W_OPEN|FDS_SAME, m_epoll_event:{events:, data:FD:0x55a875899140}}, 32, FD:0x55a875899140)
EVIO : Incremented m_active to 1
EVIO : Incremented ref count (now 4) [FD:0x55a875899140]
SYSTEM : epoll_ctl(14, EPOLL_CTL_ADD, 15, {{events:EPOLLIN|EPOLLET, data:FD:0x55a875899140}}) = 0
EVIO : Entering OutputDevice::start_output_device({m_flags:FDS_RW|FDS_R_OPEN|FDS_W_OPEN|FDS_SAME|FDS_R_ADDED|FDS_R_ACTIVE, m_epoll_event:{events:EPOLLIN|EPOLLET, data:FD:0x55a875899140}}) [FD:0x55a875899140]
EVIO : Entering EventLoopThread::start({m_flags:FDS_RW|FDS_R_OPEN|FDS_W_OPEN|FDS_SAME|FDS_R_ADDED|FDS_R_ACTIVE, m_epoll_event:{events:EPOLLIN|EPOLLET, data:FD:0x55a875899140}}, 128, FD:0x55a875899140)
EVIO : Incremented m_active to 2
SYSTEM : epoll_ctl(14, EPOLL_CTL_MOD, 15, {{events:EPOLLIN|EPOLLOUT|EPOLLET, data:FD:0x55a875899140}}) = 0
EVIO : Entering StreamBuf::xsputn_a("GET /\r\n", 7) [0x55a8758d64c0] = 7
EVIO : Entering TLSSocket::sync()
EventLoopThr SYSTEM : <continued> 1
TLS : m_session_state == preconnect
EventLoopThr EVIO : epoll_pwait new event(s): EPOLLOUT
IO : Decremented ref count of device FD:0x55a875899140 to 3
EVIO : Entering EventLoop::~EventLoop()
EventLoopThr EVIO : Queuing I/O event EPOLLOUT for FD:0x55a875899140 in thread pool queue #0
EVIO : Entering EventLoopThread::terminate(1)
EventLoopThr SYSTEM : epoll_pwait() = <unfinished>
EVIO : Sending wake-up signal 34
ThreadPool06 THREADPOOL : Beginning of thread pool main loop (q = #0)
EventLoopThr SYSTEM : FD:0x55a875899140: 15, FDS_RW|FDS_R_OPEN|FDS_W_OPEN|FDS_SAME|FDS_R_ADDED|FDS_W_ADDED|FDS_R_ACTIVE|FDS_W_ACTIVE
EVIO : Joining m_event_thread... <unfinished>
ThreadPool06 THREADPOOL : Not going idle.
EventLoopThr SYSTEM : <continued> -1: EINTR (Interrupted system call)
ThreadPool06 EVIO : Beginning of handling event EPOLLOUT for FD:0x55a875899140.
EventLoopThr SYSTEM : epoll_pwait() = <unfinished>
ThreadPool06 EVIO : Entering TLSSocket::write_to_fd({1}, 15) [FD:0x55a875899140]
ThreadPool06 EVIO : m_session_state == preconnect
EventLoopThr SYSTEM : FD:0x55a875899140: 15, FDS_RW|FDS_R_OPEN|FDS_W_OPEN|FDS_SAME|FDS_R_ADDED|FDS_W_ADDED|FDS_R_ACTIVE|FDS_W_ACTIVE
ThreadPool06 TLS : Entering TLS::session_init("www.google.com")
ThreadPool06 TLS : wolfSSL_new(0x55a875899270) = 0x7f14bc0018d0
ThreadPool06 TLS : wolfSSL_set_fd(0x7f14bc0018d0, 15) = SSL_SUCCESS
ThreadPool06 EVIO : session_state = handshake_want_write
ThreadPool06 TLS : wolfSSL_connect(0x7f14bc0018d0) = SSL_FATAL_ERROR (WOLFSSL_ERROR_WANT_READ: non-blocking socket wants data to be read)
ThreadPool06 TLS : wolfSSL_want_read(0x7f14bc0018d0) returned true.
ThreadPool06 EVIO : Entering OutputDevice::stop_output_device({1}) [FD:0x55a875899140]
ThreadPool06 SYSTEM : epoll_ctl(14, EPOLL_CTL_MOD, 15, {{events:EPOLLIN|EPOLLET, data:FD:0x55a875899140}}) = 0
ThreadPool06 EVIO : Decremented m_active to 1
ThreadPool06 EVIO : flags are now: FDS_RW|FDS_R_OPEN|FDS_W_OPEN|FDS_SAME|FDS_R_ADDED|FDS_W_ADDED|FDS_R_ACTIVE
ThreadPool06 EVIO : session_state == handshake_want_read
ThreadPool06 TLS : Set m_session_state to session_state (handshake_want_read).
ThreadPool06 EVIO : Entering FileDescriptor::clear_pending_output_events(14, EPOLLOUT) [FD:0x55a875899140] returning new events: none
ThreadPool06 IO : Decremented ref count of device FD:0x55a875899140 to 3
ThreadPool06 THREADPOOL : task() returned 0
ThreadPool06 THREADPOOL : Beginning of thread pool main loop (q = #0)
EventLoopThr SYSTEM : <continued> 1
EventLoopThr EVIO : epoll_pwait new event(s): EPOLLIN
EventLoopThr EVIO : Queuing I/O event EPOLLIN for FD:0x55a875899140 in thread pool queue #0
ThreadPool06 THREADPOOL : Beginning of thread pool main loop (q = #0)
EventLoopThr SYSTEM : epoll_pwait() = <unfinished>
ThreadPool06 THREADPOOL : Not going idle.
ThreadPool06 EVIO : Beginning of handling event EPOLLIN for FD:0x55a875899140.
EventLoopThr SYSTEM : FD:0x55a875899140: 15, FDS_RW|FDS_R_OPEN|FDS_W_OPEN|FDS_SAME|FDS_R_ADDED|FDS_W_ADDED|FDS_R_ACTIVE
ThreadPool06 EVIO : Entering TLSSocket::read_from_fd({1}, 15) [FD:0x55a875899140]
ThreadPool06 TLS : m_session_state == handshake_want_read
EventLoopThr SYSTEM : <continued> 1
EventLoopThr EVIO : epoll_pwait event(s) EPOLLIN of fd FD:0x55a875899140 ignored because the event(s) EPOLLIN is/are already being handled by the thread pool.
EventLoopThr SYSTEM : epoll_pwait() = <unfinished>
EventLoopThr SYSTEM : FD:0x55a875899140: 15, FDS_RW|FDS_R_OPEN|FDS_W_OPEN|FDS_SAME|FDS_R_ADDED|FDS_W_ADDED|FDS_R_ACTIVE
ThreadPool06 TLS : wolfSSL_connect(0x7f14bc0018d0) = SSL_FATAL_ERROR (WOLFSSL_ERROR_WANT_READ: non-blocking socket wants data to be read)
ThreadPool06 TLS : wolfSSL_want_read(0x7f14bc0018d0) returned true.
ThreadPool06 EVIO : Entering FileDescriptor::clear_pending_input_event(14) [FD:0x55a875899140]
ThreadPool06 SYSTEM : epoll_ctl(14, EPOLL_CTL_MOD, 15, {{events:EPOLLIN|EPOLLET, data:FD:0x55a875899140}}) = 0
ThreadPool06 IO : Decremented ref count of device FD:0x55a875899140 to 3
ThreadPool06 THREADPOOL : task() returned 0
ThreadPool06 THREADPOOL : Beginning of thread pool main loop (q = #0)
EventLoopThr SYSTEM : <continued> 1
EventLoopThr EVIO : epoll_pwait new event(s): EPOLLIN
EventLoopThr EVIO : Queuing I/O event EPOLLIN for FD:0x55a875899140 in thread pool queue #0
EventLoopThr SYSTEM : epoll_pwait() = <unfinished>
ThreadPool06 THREADPOOL : Beginning of thread pool main loop (q = #0)
ThreadPool06 THREADPOOL : Not going idle.
EventLoopThr SYSTEM : FD:0x55a875899140: 15, FDS_RW|FDS_R_OPEN|FDS_W_OPEN|FDS_SAME|FDS_R_ADDED|FDS_W_ADDED|FDS_R_ACTIVE
ThreadPool06 EVIO : Beginning of handling event EPOLLIN for FD:0x55a875899140.
EventLoopThr SYSTEM : <continued> 1
ThreadPool06 EVIO : Entering TLSSocket::read_from_fd({1}, 15) [FD:0x55a875899140]
EventLoopThr EVIO : epoll_pwait event(s) EPOLLIN of fd FD:0x55a875899140 ignored because the event(s) EPOLLIN is/are already being handled by the thread pool.
ThreadPool06 TLS : m_session_state == handshake_want_read
EventLoopThr SYSTEM : epoll_pwait() = <unfinished>
EventLoopThr SYSTEM : FD:0x55a875899140: 15, FDS_RW|FDS_R_OPEN|FDS_W_OPEN|FDS_SAME|FDS_R_ADDED|FDS_W_ADDED|FDS_R_ACTIVE
ThreadPool06 TLS : wolfSSL_connect(0x7f14bc0018d0) = SSL_FATAL_ERROR (WOLFSSL_ERROR_WANT_READ: non-blocking socket wants data to be read)
ThreadPool06 TLS : wolfSSL_want_read(0x7f14bc0018d0) returned true.
ThreadPool06 EVIO : Entering FileDescriptor::clear_pending_input_event(14) [FD:0x55a875899140]
ThreadPool06 SYSTEM : epoll_ctl(14, EPOLL_CTL_MOD, 15, {{events:EPOLLIN|EPOLLET, data:FD:0x55a875899140}}) = 0
ThreadPool06 IO : Decremented ref count of device FD:0x55a875899140 to 3
ThreadPool06 THREADPOOL : task() returned 0
ThreadPool06 THREADPOOL : Beginning of thread pool main loop (q = #0)
EventLoopThr SYSTEM : <continued> 1
EventLoopThr EVIO : epoll_pwait new event(s): EPOLLIN
EventLoopThr EVIO : Queuing I/O event EPOLLIN for FD:0x55a875899140 in thread pool queue #0
ThreadPool06 THREADPOOL : Beginning of thread pool main loop (q = #0)
EventLoopThr SYSTEM : epoll_pwait() = <unfinished>
ThreadPool06 THREADPOOL : Not going idle.
ThreadPool06 EVIO : Beginning of handling event EPOLLIN for FD:0x55a875899140.
ThreadPool06 EVIO : Entering TLSSocket::read_from_fd({1}, 15) [FD:0x55a875899140]
EventLoopThr SYSTEM : FD:0x55a875899140: 15, FDS_RW|FDS_R_OPEN|FDS_W_OPEN|FDS_SAME|FDS_R_ADDED|FDS_W_ADDED|FDS_R_ACTIVE
ThreadPool06 TLS : m_session_state == handshake_want_read
EventLoopThr SYSTEM : <continued> 1
EventLoopThr EVIO : epoll_pwait event(s) EPOLLIN of fd FD:0x55a875899140 ignored because the event(s) EPOLLIN is/are already being handled by the thread pool.
EventLoopThr SYSTEM : epoll_pwait() = <unfinished>
EventLoopThr SYSTEM : FD:0x55a875899140: 15, FDS_RW|FDS_R_OPEN|FDS_W_OPEN|FDS_SAME|FDS_R_ADDED|FDS_W_ADDED|FDS_R_ACTIVE
ThreadPool06 TLS : wolfSSL_connect(0x7f14bc0018d0) = SSL_SUCCESS
ThreadPool06 EVIO : Entering OutputDevice::start_output_device({m_flags:FDS_RW|FDS_R_OPEN|FDS_W_OPEN|FDS_SAME|FDS_R_ADDED|FDS_W_ADDED|FDS_R_ACTIVE, m_epoll_event:{events:EPOLLIN|EPOLLET, data:FD:0x55a875899140}}, {FuzzyCondition: before: fuzzy::True, after: fuzzy::True}) [FD:0x55a875899140]
ThreadPool06 COREDUMP : /home/carlo/projects/aicxx/ai-evio-testsuite/ai-evio-testsuite/evio/OutputDevice.cxx:112: bool evio::OutputDevice::start_output_device(const state_t::wat &, const utils::FuzzyCondition &): Assertion `condition.is_transitory_true()' failed.Or, if you rather just see the wolfssl calls - look at the debug channel 'TLS':
TLS : wolfSSL_Init() = SSL_SUCCESS
TLS : wolfSSL_CTX_new(wolfTLS_client_method()) = 0x55a36e17bf20
TLS : wolfSSL_CTX_SetMinVersion(0x55a36e17bf20, WOLFSSL_TLSV1_2) = SSL_SUCCESS
TLS : wolfSSL_CTX_load_verify_locations(s_context, "/etc/ssl/cert.pem", NULL) = SSL_SUCCESS
TLS : wolfSSL_CTX_load_verify_locations(s_context, "/usr/src/AUR/wolfssl/wolfssl-examples-git/certs/ca-cert.pem", NULL) = SSL_SUCCESS
ThreadPool19 TLS : wolfSSL_new(0x55a36e17bf20) = 0x7fcaac0018d0
ThreadPool19 TLS : wolfSSL_set_fd(0x7fcaac0018d0, 15) = SSL_SUCCESS
ThreadPool19 TLS : wolfSSL_connect(0x7fcaac0018d0) = SSL_FATAL_ERROR (WOLFSSL_ERROR_WANT_READ: non-blocking socket wants data to be read)
ThreadPool19 TLS : wolfSSL_want_read(0x7fcaac0018d0) returned true.
ThreadPool19 TLS : wolfSSL_connect(0x7fcaac0018d0) = SSL_FATAL_ERROR (WOLFSSL_ERROR_WANT_READ: non-blocking socket wants data to be read)
ThreadPool19 TLS : wolfSSL_want_read(0x7fcaac0018d0) returned true.
ThreadPool19 TLS : wolfSSL_connect(0x7fcaac0018d0) = SSL_FATAL_ERROR (WOLFSSL_ERROR_WANT_READ: non-blocking socket wants data to be read)
ThreadPool19 TLS : wolfSSL_want_read(0x7fcaac0018d0) returned true.
ThreadPool19 TLS : wolfSSL_connect(0x7fcaac0018d0) = SSL_FATAL_ERROR (WOLFSSL_ERROR_WANT_READ: non-blocking socket wants data to be read)
ThreadPool19 TLS : wolfSSL_want_read(0x7fcaac0018d0) returned true.
ThreadPool19 TLS : wolfSSL_connect(0x7fcaac0018d0) = SSL_FATAL_ERROR (WOLFSSL_ERROR_WANT_READ: non-blocking socket wants data to be read)
ThreadPool19 TLS : wolfSSL_want_read(0x7fcaac0018d0) returned true.
ThreadPool19 TLS : wolfSSL_connect(0x7fcaac0018d0) = SSL_SUCCESSHi dgarske, thank you for your reply!
You confirm what I suspected; that it is not needed to call `wolfSSL_set_using_nonblock`.
Both, documentation and examples are really lagging behind - I run constantly into incorrect
things in both .
Note that the example that you link to DOES call `wolfSSL_set_using_nonblock`,
unnecessary (it does nothing, at best), but slightly confusing that you link to it in this context
therefore...
The documentation at https://www.wolfssl.com/doxygen/group__ … 5417fc8f3a
says:
After an application creates a WOLFSSL object, if it will be used with a non-blocking socket, call wolfSSL_set_using_nonblock() on it.
However, in the source code I found:
/* Nonblocking DTLS helper functions */
WOLFSSL_API void wolfSSL_dtls_set_using_nonblock(WOLFSSL*, int);
WOLFSSL_API int wolfSSL_dtls_get_using_nonblock(WOLFSSL*);
#define wolfSSL_set_using_nonblock wolfSSL_dtls_set_using_nonblock
#define wolfSSL_get_using_nonblock wolfSSL_dtls_get_using_nonblock
/* The old names are deprecated. */In other words, `wolfSSL_set_using_nonblock()` doesn't even really exist.
It seems from this that one should call `wolfSSL_dtls_set_using_nonblock()`
when using DTLS, and not when using -say- a non-blocking TCP socket.
Documentation wrong again?
Hello,
like I said before, I'm integrating wolfSSL into my C++ library. Maintainability and flexibility require wolfSLL's API to be wrapped, of course. Not only that, I wrap it in C++ classes where possible which can encapsulate requirements that make my code more robust.
All in all, I'm free to chose my own names for things. And I believe that using the Right Names in a program is very important.
Until now I used the name 'session' for a (wrapped) WOLFSSL struct. This seemed logical because I viewed making an actual connection to a server, doing the TLS handshake and starting to use the socket for encrypted communication to be one "session".
However, then I ran into `struct WOLFSSL_SESSION` and now I'm confused. If there is something like an SSL session concept, then I suppose this means that you can lose your server connection, but re-establish it (doing another handshake or whatever) without that the user notices this: they can just continue with what they were doing using the (re-established) encrypted channel.
I am not sure how this works, but I can imagine that re-establishing a secure connection, even if it uses the same socket (fd), requires the creation of a new WOLFSSL? In that case there is a clear distinction between a 'session' (from the user point of view, there is just one), and a WOLFSSL struct, that represents ... well, what?
I don't want to call my classes/functions 'ssl' (as wolfssl does internally). That stands for 'Secure Socket Layer', and that is not what it represents.
I was contemplating `ssl_connection`.
So, what exactly does a WOLFSSL struct represent? Would 'SSL connection' be a good description?
Perhaps I should phrase it as follows:
If you had to rename your WOLFSSL struct to "WOLFSSL_SOMETHING", what would you use for the SOMETHING?
Thanks,
I suppose it is debatable how serious failure to cleanup is when there is a fatal error to initialize wolfssl: it that case it is likely that the program will be terminated anyway.
The reason I fell over this however is because I'm integrating wolfssl with my C++ library and found myself calling wolfSSL_init() from the constructor of a class:
TLS::TLS() : m_session(nullptr)
{
DoutEntering(dc::tls, "TLS::TLS() [" << this << "]");
std::call_once(s_flag, global_tls_initialization);
}where
//static
void TLS::global_tls_initialization()
{
DoutEntering(dc::tls|dc::notice, "evio::protocol::TLS::global_tls_initialization()");
// Call this to have wolfssl print debug output (wolfssl must be configured with --enable-debug).
//wolfSSL_Debugging_ON();
Dout(dc::tls|continued_cf, "wolfSSL_Init() = ");
wolfssl_error_code ret = wolfSSL_Init();
Dout(dc::finish, ret);
if (ret != WOLFSSL_SUCCESS)
THROW_FALERTC(ret, "wolfSSL_Init");
...At that point, where I possibly throw an exception from a constructor, I feel strongly obliged to make SURE that there are no side effects from the constructor. A constructor that throws should have the effect like it wasn't called at all. This is just a holy rule that is etched into my coding habbits;
so, I naturally looked inside `wolfSSL_Init()` to make sure it had no side effects when it returned something other than WOLFSSL_SUCCESS.
In theory, it would be OK when wolfSSL_Init() had side effect (from the C coding point of view), but in that case it would be nice if it returned an error that allowed me to unwind all the damage. But that is certainly not possible, if only because it returns the same error codes from different stages of initialization.
My approach is currently to use, after the initial initialization,
wolfSSL_connect(ssl)
wolfSSL_write(ssl, data, sz)
wolfSSL_read(ssl, data, sz)Depending on whether or not `wolfSSL_connect(ssl)` already returned SSL_SUCCESS, indicating
the end of the handshake, I either call `wolfSSL_connect(ssl)` OR `wolfSSL_write(ssl, data, sz)`
whenever the socket fs is writable - and I was monitoring the socket for writability of course.
And I either call `wolfSSL_connect(ssl)` OR `wolfSSL_read(ssl, data, sz)` whenever there is
something to read on the socket fd.
One of the problems here is to know when to monitor the fd for writability: we only want to do
that when we have something to write, nl.,
1. Immediately after initialization: this is when the client HELLO message needs to be written.
2. When the last call to `wolfSSL_connect(ssl)` returned WANT_WRITE.
3. When the last call to `wolfSSL_write(ssl, data, sz)` returned WANT_WRITE.
4. When the handshake is finished and I have application data in the plain text buffer that I want to write.
Monitoring the fd for readability is basically always on, as it doesn't hurt.
However, my library (that I'm integrating with wolfssl) is able to read and write the same socket
at the same time, using two different threads (and separate input/output buffers).
So, it can happen that the socket becomes readable or writable while I'm already calling
one the mentioned functions.
In the ideal case, wolfsll would be able to deal with this. Not by blocking(!) but by having reading
and writing totally separated.
But is this the case?
For example, can I call `wolfSSL_write(ssl, data, sz)` and `wolfSSL_read(ssl, data, sz)` at
the same time (with the same ssl) in parallel?
Or, what if I'm calling `wolfSSL_connect(ssl)` from the write thread (because it was in the
state WANT_WRITE) and while doing so I'm receiving a message from the server (could
be anything - an ssl alert - or whatever, we can't rule it out), then what is the right action
to take?
On that note, does wolfSLL handle ssl alerts? How?
There is no documentation on the website that I can find (search returns "no matches").
However, there is documentation in the source tree (doc/dox_comments/header_files/ssl.h) for `wolfSSL_UseSNI` which states:
\return SSL_SUCCESS upon success
followed by example code:
ret = wolfSSL_UseSNI(ssl, WOLFSSL_SNI_HOST_NAME, "www.yassl.com", strlen("www.yassl.com"));
if (ret != 0) {
// sni usage failed
}Note that `SSL_SUCCESS` is a (deprecated?) old name, at most defined to be `WOLFSSL_SUCCESS` which is equal 1, not 0.
Looking at the actual code,
`wolfSSL_UseSNI` returns `TLSX_UseSNI` which returns, upon errors, the negative values BAD_FUNC_ARG or MEMORY_E but also contains the code:
if (ret != 0) {
TLSX_SNI_Free(sni, heap);
return ret;
}
...
return WOLFSSL_SUCCESS;The last line matches the documentation (but not the example) but the first line feels error prone.
Looking more closely to the actual code and functions called, we can establish that this won't
return the value 1 (WOLFSSL_SUCCESS) after just having freed sni... But it doesn't look very
robust to me.
There seems to be a duality in the code on what the meaning of the return value '0' means.
Sometimes it means 'success' and sometimes it means WOLFSSL_FAILURE.
Proof that this is bad is the fact that the documentation contains examples that confuse the two.
In wolfSSL_init(), if initRefCount == 0 when called and when wolfCrypt_Init() returns 0 (succeeds), then after that wolfCrypt_Cleanup() is not called if subsequently any additional error occurs.
Likewise, if the call to wolfSSL_RAND_seed succeeds, but an error happens after that then also wolfSSL_RAND_Cleanup() is not called to clean up.
Finally, if `wc_InitMutex(&session_mutex)` succeeds, but an error happens after that then `wc_FreeMutex` is not called and
if `wc_InitMutex(&count_mutex)` succeeds but `wc_LockMutex(&count_mutex)` fails, then again `wc_FreeMutex` is not called.
I did some investigation and found the following:
The struct ProtocolVersion can contain a single protocol version (by major and minor version number).
The struct WOLFSSL_METHOD reflects the negotiation method and contains the following fields,
/* wolfSSL method type */
struct WOLFSSL_METHOD {
ProtocolVersion version;
byte side; /* connection side, server or client */
byte downgrade; /* whether to downgrade version, default no */
};The (much larger) struct Options contains a field `downgrade` (one bit) and a byte field `minDowngrade` which is
the minimum minor version of the protocol that will be negotiated (or so it seems from the source code).
The function `void InitSSL_Method(WOLFSSL_METHOD* method, ProtocolVersion pv)` initializes
the `WOLFSSL_METHOD` passed with the `ProtocolVersion` passed and sets `side` to `WOLFSSL_CLIENT_END`
and `downgrade` to 0.
The following functions set the byte field of struct WOLFSSL_METHOD called `downgrade` to 1 and leave
the `side` field at `WOLFSSL_CLIENT_END` (as opposed to setting it to `WOLFSSL_SERVER_END`):
wolfSSLv23_client_method()
wolfTLS_client_method()
wolfDTLS_client_method()Note that (apart from horrible code duplication) `wolfTLS_client_method()` initializes the `ProtocolVersion` field with TLS 1.0, 1.1, 1.2 or 1.3, whichever version is the highest that is compiled into the library. While `wolfSSLv23_client_method()` initializes the `ProtocolVersion` field with TLS 1.1, 1.2 or 1.3, whichever version is the highest compiled in - and if none is compiled in it simply leaves the structure uninitialized for a nice crash or other undefined behavior.
Assuming nobody in their right mind will compile wolfssl without support for TLS 1.3 for now, both functions do the exact same thing; but it seems to me that `wolfSSLv23_client_method`is broken in multiple ways.
The struct WOLFSSL_CTX also has a `minDowngrade` field. This field is copied to WOLFSSL->options.minDowngrade in `SetSSL_CTX`. It is also set in `dtls_export_load` which I will ignore. Finally options.minDowngrade seems to be changed by `SetMinVersionHelper` when called from `wolfSSL_SetMinVersion` (https://www.wolfssl.com/doxygen/group__ … 92e0c5c4f5) [Note the outdated / incorrect documentation there: there is no mention of wolfTLS_client_method() or wolfDTLS_client_method()].
Likewise it is possible to change the `minDowngrade` field in the WOLFSSL_CTX struct with `wolfSSL_CTX_SetMinVersion`.
In summary, my conclusion is that the answer to okba.zoueghi's question is that one has to use `ctx = wolfSSL_CTX_new(wolfTLS_client_method())` and then either call `wolfSSL_CTX_SetMinVersion(ctx, WOLFSSL_TLSV1_1)` prior to creating a WOLFSSL with `ssl = wolfSSL_new(ctx)`, or call wolfSSL_SetMinVersion(ssl, WOLFSSL_TLSV1_1) afterwards.
Here is a snippet of my test code:
/* declare wolfSSL objects */
WOLFSSL_CTX* ctx;
/* Create and initialize WOLFSSL_CTX */
if ((ctx = wolfSSL_CTX_new(wolfTLS_client_method())) == NULL) {
fprintf(stderr, "ERROR: failed to create WOLFSSL_CTX\n");
goto init_cleanup;
}
// Demand at least TLS version 1.2.
wolfSSL_CTX_SetMinVersion(ctx, WOLFSSL_TLSV1_2);Which should try to negotiate TLS 1.3 and if that fails try TLS 1.2 and if that fails give up.
I have the exact same question as okba.zoueghi : how can I hand pick the protocol versions that I want to negotiate?
It seems that you either support a single protocol/version (ie, ONLY TLS 1.1 and nothing else) OR one has to use wolfSSLv23_client_method() and run the risk that something is negotiated that you don't want (e.g. SSL 3.0, or TLS 1.0).
It seems that the user is not able to select exactly which protocols (and signature algorithms and ciphersuites for that matter) they are willing to accept during negotiation.
More than a year later...
Still no mention of TLS v1.3 on https://www.wolfssl.com/docs/wolfssl-manual/ch11/
Who is this document maintainer that you asked to update this?
I also had a discussion on freenode with fellow Arch Linux users and the consensus was that it was "utter nonsense" not to install options.h.
That is, --enable-distro can be explained as "this is what all distributions should use in order to have a consistent configuration of wolfssl on all linux platforms", but then options.h should still be installed. Not installing options.h just seems wrong.
There is this single remark that I found concerning the matter:
In `wolfssl/include.am`,
# For distro build don't install options.h.
# It depends on the architecture and conflicts with Multi-Arch.
if BUILD_DISTRO
noinst_HEADERS+= wolfssl/options.h
else
nobase_include_HEADERS+= wolfssl/options.h
endifApparently we have a different options.h for each architecture.
I found an a package on ubuntu that does this: libssl.
This installs for i386 and amd64 architectures the same headers, except for
one:
sean:~>dpkg -L libssl-dev:i386 | grep opensslconf.h
/usr/include/i386-linux-gnu/openssl/opensslconf.h
sean:~>dpkg -L libssl-dev:amd64 | grep opensslconf.h
/usr/include/x86_64-linux-gnu/openssl/opensslconf.hthe rest of the headers in both cases are installed in `/usr/include/openssl`.
They also install their own respective `*.pc` files in `/usr/lib/i386-linux-gnu/pkgconfig`
and `/usr/lib/x86_64-linux-gnu/pkgconfig`.
This is how Multi-Arch works. While /usr/lib and /usr/include are
the normal directories, depending on the current architectures
that is being compiled for, also /usr/lib/<arch> and /usr/include/<arch>
are searched.
[The "main" <arch> path can be printed with `gcc -print-multiarch`.
Note that on Arch Linux that prints nothing, because there is no
/usr/lib/x86_64-linux-gnu on Arch (which basically only supports 64bit).]
So, correct me if I'm wrong but I will now assume that distributions are
responsible for installing options.h themselves, in the right place - as
opposed to not installing it at all.
PS So it seems that debian is doing this wrong.
If wolfssl packages included with distribitions should be configured with --enable-distro and subsequently don't have options.h installed,
then the user can't #include options.h, right?
But when I don't, I get the following warning:
In file included from /usr/local/include/wolfssl/ssl.h:33:
/usr/local/include/wolfssl/wolfcrypt/settings.h:2124:14: warning: "For timing resistance / side-channel attack prevention consider using harden options" [-W#warnings]
#warning "For timing resistance / side-channel attack prevention consider using harden options"Does this mean that the (default) configuration used for distros is not hardened?
Or is something worse wrong?
Pages 1
wolfSSL - Embedded SSL Library → Posts by carlo
Powered by PunBB, supported by Informer Technologies, Inc.
Generated in 0.018 seconds (95% PHP - 5% DB) with 5 queries