RE: [stunnel-users] Newbie: Keep getting connection closed
Charles, Check to see if you are being bitten by the "Eudora" problem -- add the following line to the top of your stunnel.conf file, and see if it magically starts working: options = DONT_INSERT_EMPTY_FRAGMENTS You can also see a related set of mails from myself, describing the problem we had. Regards, David Hansen -----Original Message----- From: stunnel-users-admin@mirt.net [mailto:stunnel-users-admin@mirt.net]On Behalf Of Charles A. Monteiro Sent: Dienstag, 17. August 2004 18:31 To: stunnel-users@mirt.net Subject: [stunnel-users] Newbie: Keep getting connection closed We are using a proprietary protocol over tcp/ip which works fine and has for a number of years. I have tested it without stunnel and it checks fine as well. I keep getting the connection closed when I run through stunnel. I don't understand if something bad has actually happened i.e. from the error warnings. Is an "alert" a bad thing i.e. does it indicate that something is broken? Does stunnel normally close the connection after every message exchange? I have included the logs for both the stunnel client and server as well as the respective conf files. thanks in advance, -Charles --------------------------------------- client log: 2004.08.17 11:13:27 LOG7[1824:1544]: 55555 accepted FD=536 from 127.0.0.1:1085 2004.08.17 11:13:27 LOG7[1824:1544]: FD 536 in non-blocking mode 2004.08.17 11:13:27 LOG7[1824:1544]: Creating a new thread 2004.08.17 11:13:27 LOG7[1824:1544]: New thread created 2004.08.17 11:13:27 LOG7[1824:1040]: 55555 started 2004.08.17 11:13:27 LOG5[1824:1040]: 55555 connected from 127.0.0.1:1085 2004.08.17 11:13:27 LOG7[1824:1040]: FD 564 in non-blocking mode 2004.08.17 11:13:27 LOG7[1824:1040]: 55555 connecting 192.168.20.76:55555 2004.08.17 11:13:27 LOG7[1824:1040]: remote connect #1: EWOULDBLOCK: retrying 2004.08.17 11:13:27 LOG7[1824:1040]: waitforsocket: FD=564, DIR=write 2004.08.17 11:13:27 LOG7[1824:1040]: waitforsocket: ok 2004.08.17 11:13:27 LOG7[1824:1040]: Remote FD=564 initialized 2004.08.17 11:13:27 LOG7[1824:1040]: SSL state (connect): before/connect initialization 2004.08.17 11:13:27 LOG7[1824:1040]: SSL state (connect): SSLv3 write client hello A 2004.08.17 11:13:27 LOG7[1824:1040]: SSL state (connect): SSLv3 read server hello A 2004.08.17 11:13:27 LOG7[1824:1040]: SSL state (connect): SSLv3 read server certificate A 2004.08.17 11:13:27 LOG7[1824:1040]: SSL state (connect): SSLv3 read server done A 2004.08.17 11:13:27 LOG7[1824:1040]: SSL state (connect): SSLv3 write client key exchange A 2004.08.17 11:13:27 LOG7[1824:1040]: SSL state (connect): SSLv3 write change cipher spec A 2004.08.17 11:13:27 LOG7[1824:1040]: SSL state (connect): SSLv3 write finished A 2004.08.17 11:13:27 LOG7[1824:1040]: SSL state (connect): SSLv3 flush data 2004.08.17 11:13:27 LOG7[1824:1040]: waitforsocket: FD=564, DIR=read 2004.08.17 11:13:27 LOG7[1824:1040]: waitforsocket: ok 2004.08.17 11:13:27 LOG7[1824:1040]: SSL state (connect): SSLv3 read finished A 2004.08.17 11:13:27 LOG7[1824:1040]: 6 items in the session cache 2004.08.17 11:13:27 LOG7[1824:1040]: 7 client connects (SSL_connect()) 2004.08.17 11:13:27 LOG7[1824:1040]: 7 client connects that finished 2004.08.17 11:13:27 LOG7[1824:1040]: 0 client renegotiatations requested 2004.08.17 11:13:27 LOG7[1824:1040]: 0 server connects (SSL_accept()) 2004.08.17 11:13:27 LOG7[1824:1040]: 0 server connects that finished 2004.08.17 11:13:27 LOG7[1824:1040]: 0 server renegotiatiations requested 2004.08.17 11:13:27 LOG7[1824:1040]: 1 session cache hits 2004.08.17 11:13:27 LOG7[1824:1040]: 0 session cache misses 2004.08.17 11:13:27 LOG7[1824:1040]: 0 session cache timeouts 2004.08.17 11:13:27 LOG6[1824:1040]: Negotiated ciphers: AES256-SHA SSLv3 Kx=RSA Au=RSA Enc=AES(256) Mac=SHA1 2004.08.17 11:13:27 LOG7[1824:1040]: Socket closed on read 2004.08.17 11:13:27 LOG7[1824:1040]: SSL write shutdown (output buffer empty) 2004.08.17 11:13:27 LOG7[1824:1040]: SSL alert (write): warning: close notify 2004.08.17 11:13:27 LOG7[1824:1040]: SSL_shutdown retrying 2004.08.17 11:13:27 LOG7[1824:1040]: SSL alert (read): warning: close notify 2004.08.17 11:13:27 LOG7[1824:1040]: SSL closed on SSL_read 2004.08.17 11:13:27 LOG7[1824:1040]: Socket write shutdown (output buffer empty) 2004.08.17 11:13:27 LOG5[1824:1040]: Connection closed: 110 bytes sent to SSL, 13 bytes sent to socket 2004.08.17 11:13:27 LOG7[1824:1040]: 55555 finished (0 left) ------------------------------------------------------------- server log: 2004.08.17 11:03:12 LOG7[28177:3073021920]: 55555 accepted FD=7 from 192.168.20.77:1086 2004.08.17 11:03:12 LOG7[28177:3073021920]: FD 7 in non-blocking mode 2004.08.17 11:03:12 LOG7[28177:3062528944]: 55555 started 2004.08.17 11:03:12 LOG5[28177:3062528944]: 55555 connected from 192.168.20.77:1086 2004.08.17 11:03:12 LOG7[28177:3062528944]: SSL state (accept): before/accept initialization 2004.08.17 11:03:12 LOG7[28177:3062528944]: waitforsocket: FD=7, DIR=read 2004.08.17 11:03:12 LOG7[28177:3062528944]: waitforsocket: ok 2004.08.17 11:03:12 LOG7[28177:3062528944]: SSL state (accept): SSLv3 read client hello A 2004.08.17 11:03:12 LOG7[28177:3062528944]: SSL state (accept): SSLv3 write server hello A 2004.08.17 11:03:12 LOG7[28177:3062528944]: SSL state (accept): SSLv3 write certificate A 2004.08.17 11:03:12 LOG7[28177:3062528944]: SSL state (accept): SSLv3 write server done A 2004.08.17 11:03:12 LOG7[28177:3062528944]: SSL state (accept): SSLv3 flush data 2004.08.17 11:03:12 LOG7[28177:3062528944]: waitforsocket: FD=7, DIR=read 2004.08.17 11:03:12 LOG7[28177:3062528944]: waitforsocket: ok 2004.08.17 11:03:12 LOG7[28177:3062528944]: SSL state (accept): SSLv3 read client key exchange A 2004.08.17 11:03:12 LOG7[28177:3062528944]: SSL state (accept): SSLv3 read finished A 2004.08.17 11:03:12 LOG7[28177:3062528944]: SSL state (accept): SSLv3 write change cipher spec A 2004.08.17 11:03:12 LOG7[28177:3062528944]: SSL state (accept): SSLv3 write finished A 2004.08.17 11:03:12 LOG7[28177:3062528944]: SSL state (accept): SSLv3 flush data 2004.08.17 11:03:12 LOG7[28177:3062528944]: 2 items in the session cache 2004.08.17 11:03:12 LOG7[28177:3062528944]: 0 client connects (SSL_connect()) 2004.08.17 11:03:12 LOG7[28177:3062528944]: 0 client connects that finished 2004.08.17 11:03:12 LOG7[28177:3062528944]: 0 client renegotiatations requested 2004.08.17 11:03:12 LOG7[28177:3062528944]: 18 server connects (SSL_accept()) 2004.08.17 11:03:12 LOG7[28177:3062528944]: 10 server connects that finished 2004.08.17 11:03:12 LOG7[28177:3062528944]: 0 server renegotiatiations requested 2004.08.17 11:03:12 LOG7[28177:3062528944]: 2 session cache hits 2004.08.17 11:03:12 LOG7[28177:3062528944]: 0 session cache misses 2004.08.17 11:03:12 LOG7[28177:3062528944]: 6 session cache timeouts 2004.08.17 11:03:12 LOG6[28177:3062528944]: Negotiated ciphers: AES256-SHA SSLv3 Kx=RSA Au=RSA Enc=AES(256) Mac=SHA1 2004.08.17 11:03:12 LOG7[28177:3062528944]: FD 8 in non-blocking mode 2004.08.17 11:03:12 LOG7[28177:3062528944]: 55555 connecting 192.168.20.76:4242 2004.08.17 11:03:12 LOG7[28177:3062528944]: remote connect #1: EINPROGRESS: retrying 2004.08.17 11:03:12 LOG7[28177:3062528944]: waitforsocket: FD=8, DIR=write 2004.08.17 11:03:12 LOG7[28177:3062528944]: waitforsocket: ok 2004.08.17 11:03:12 LOG7[28177:3062528944]: Remote FD=8 initialized 2004.08.17 11:03:12 LOG7[28177:3062528944]: Socket closed on read 2004.08.17 11:03:12 LOG7[28177:3062528944]: SSL alert (write): warning: close notify 2004.08.17 11:03:12 LOG7[28177:3062528944]: SSL write shutdown (output buffer empty) 2004.08.17 11:03:12 LOG7[28177:3062528944]: SSL alert (read): warning: close notify 2004.08.17 11:03:12 LOG7[28177:3062528944]: SSL closed on SSL_read 2004.08.17 11:03:12 LOG7[28177:3062528944]: Socket write shutdown (output buffer empty) 2004.08.17 11:03:12 LOG5[28177:3062528944]: Connection closed: 13 bytes sent to SSL, 110 bytes sent to socket 2004.08.17 11:03:12 LOG7[28177:3062528944]: 55555 finished (0 left) ------------------------------------------------------------------------------------------------------------------- My client stunnel.conf: cert=stunnel.pem client=yes debug=7 [55555] accept=localhost:55555 connect=192.168.20.76:55555 - eof - My server stunnel.conf: cert=stunnel.pem debug=7 output=stunnel.err [55555] accept=192.168.20.76:55555 connect=192.168.20.76:4242 - eof - -- Using Opera's revolutionary e-mail client: http://www.opera.com/m2/ _______________________________________________ stunnel-users mailing list stunnel-users@mirt.net http://stunnel.mirt.net/mailman/listinfo/stunnel-users Visit our website at http://www.ubs.com This message contains confidential information and is intended only for the individual named. If you are not the named addressee you should not disseminate, distribute or copy this e-mail. Please notify the sender immediately by e-mail if you have received this e-mail by mistake and delete this e-mail from your system. E-mail transmission cannot be guaranteed to be secure or error-free as information could be intercepted, corrupted, lost, destroyed, arrive late or incomplete, or contain viruses. The sender therefore does not accept liability for any errors or omissions in the contents of this message which arise as a result of e-mail transmission. If verification is required please request a hard-copy version. This message is provided for informational purposes and should not be construed as a solicitation or offer to buy or sell any securities or related financial instruments.
Unfortunately, that did not do the trick. I have confirmed that it is not hitting my app's process on the other side yet it does generate a log on the server side. Specifically, it does make the trip from the client accept port to the accept port on the server i.e. the connect port on the client conf matches the accept port on the server conf. It gets that far which is evident since there are log entries on the server log file but it never gets to my app specific process. I have debugging set in my app to trace the message which confirms this but also I don't see any entries in the log files which show that the message was ever forwarded from the stunnel server port to my app's port. What am I doing wrong? Again, confs and log entries are below. My app's port is alive and works otherwise. What reasons would prevent the stunnel port from being able to write to my app's port? thanks Charles On Tue, 17 Aug 2004 17:54:58 +0200, <david-e.hansen@ubs.com> wrote:
Charles,
Check to see if you are being bitten by the "Eudora" problem -- add the following line to the top of your stunnel.conf file, and see if it magically starts working:
options = DONT_INSERT_EMPTY_FRAGMENTS
You can also see a related set of mails from myself, describing the problem we had.
Regards,
David Hansen
-----Original Message----- From: stunnel-users-admin@mirt.net [mailto:stunnel-users-admin@mirt.net]On Behalf Of Charles A. Monteiro Sent: Dienstag, 17. August 2004 18:31 To: stunnel-users@mirt.net Subject: [stunnel-users] Newbie: Keep getting connection closed
We are using a proprietary protocol over tcp/ip which works fine and has for a number of years. I have tested it without stunnel and it checks fine as well. I keep getting the connection closed when I run through stunnel. I don't understand if something bad has actually happened i.e. from the error warnings. Is an "alert" a bad thing i.e. does it indicate that something is broken? Does stunnel normally close the connection after every message exchange? I have included the logs for both the stunnel client and server as well as the respective conf files.
thanks in advance,
-Charles
---------------------------------------
client log:
2004.08.17 11:13:27 LOG7[1824:1544]: 55555 accepted FD=536 from 127.0.0.1:1085 2004.08.17 11:13:27 LOG7[1824:1544]: FD 536 in non-blocking mode 2004.08.17 11:13:27 LOG7[1824:1544]: Creating a new thread 2004.08.17 11:13:27 LOG7[1824:1544]: New thread created 2004.08.17 11:13:27 LOG7[1824:1040]: 55555 started 2004.08.17 11:13:27 LOG5[1824:1040]: 55555 connected from 127.0.0.1:1085 2004.08.17 11:13:27 LOG7[1824:1040]: FD 564 in non-blocking mode 2004.08.17 11:13:27 LOG7[1824:1040]: 55555 connecting 192.168.20.76:55555 2004.08.17 11:13:27 LOG7[1824:1040]: remote connect #1: EWOULDBLOCK: retrying 2004.08.17 11:13:27 LOG7[1824:1040]: waitforsocket: FD=564, DIR=write 2004.08.17 11:13:27 LOG7[1824:1040]: waitforsocket: ok 2004.08.17 11:13:27 LOG7[1824:1040]: Remote FD=564 initialized 2004.08.17 11:13:27 LOG7[1824:1040]: SSL state (connect): before/connect initialization 2004.08.17 11:13:27 LOG7[1824:1040]: SSL state (connect): SSLv3 write client hello A 2004.08.17 11:13:27 LOG7[1824:1040]: SSL state (connect): SSLv3 read server hello A 2004.08.17 11:13:27 LOG7[1824:1040]: SSL state (connect): SSLv3 read server certificate A 2004.08.17 11:13:27 LOG7[1824:1040]: SSL state (connect): SSLv3 read server done A 2004.08.17 11:13:27 LOG7[1824:1040]: SSL state (connect): SSLv3 write client key exchange A 2004.08.17 11:13:27 LOG7[1824:1040]: SSL state (connect): SSLv3 write change cipher spec A 2004.08.17 11:13:27 LOG7[1824:1040]: SSL state (connect): SSLv3 write finished A 2004.08.17 11:13:27 LOG7[1824:1040]: SSL state (connect): SSLv3 flush data 2004.08.17 11:13:27 LOG7[1824:1040]: waitforsocket: FD=564, DIR=read 2004.08.17 11:13:27 LOG7[1824:1040]: waitforsocket: ok 2004.08.17 11:13:27 LOG7[1824:1040]: SSL state (connect): SSLv3 read finished A 2004.08.17 11:13:27 LOG7[1824:1040]: 6 items in the session cache 2004.08.17 11:13:27 LOG7[1824:1040]: 7 client connects (SSL_connect()) 2004.08.17 11:13:27 LOG7[1824:1040]: 7 client connects that finished 2004.08.17 11:13:27 LOG7[1824:1040]: 0 client renegotiatations requested 2004.08.17 11:13:27 LOG7[1824:1040]: 0 server connects (SSL_accept()) 2004.08.17 11:13:27 LOG7[1824:1040]: 0 server connects that finished 2004.08.17 11:13:27 LOG7[1824:1040]: 0 server renegotiatiations requested 2004.08.17 11:13:27 LOG7[1824:1040]: 1 session cache hits 2004.08.17 11:13:27 LOG7[1824:1040]: 0 session cache misses 2004.08.17 11:13:27 LOG7[1824:1040]: 0 session cache timeouts 2004.08.17 11:13:27 LOG6[1824:1040]: Negotiated ciphers: AES256-SHA SSLv3 Kx=RSA Au=RSA Enc=AES(256) Mac=SHA1 2004.08.17 11:13:27 LOG7[1824:1040]: Socket closed on read 2004.08.17 11:13:27 LOG7[1824:1040]: SSL write shutdown (output buffer empty) 2004.08.17 11:13:27 LOG7[1824:1040]: SSL alert (write): warning: close notify 2004.08.17 11:13:27 LOG7[1824:1040]: SSL_shutdown retrying 2004.08.17 11:13:27 LOG7[1824:1040]: SSL alert (read): warning: close notify 2004.08.17 11:13:27 LOG7[1824:1040]: SSL closed on SSL_read 2004.08.17 11:13:27 LOG7[1824:1040]: Socket write shutdown (output buffer empty) 2004.08.17 11:13:27 LOG5[1824:1040]: Connection closed: 110 bytes sent to SSL, 13 bytes sent to socket 2004.08.17 11:13:27 LOG7[1824:1040]: 55555 finished (0 left)
------------------------------------------------------------- server log:
2004.08.17 11:03:12 LOG7[28177:3073021920]: 55555 accepted FD=7 from 192.168.20.77:1086 2004.08.17 11:03:12 LOG7[28177:3073021920]: FD 7 in non-blocking mode 2004.08.17 11:03:12 LOG7[28177:3062528944]: 55555 started 2004.08.17 11:03:12 LOG5[28177:3062528944]: 55555 connected from 192.168.20.77:1086 2004.08.17 11:03:12 LOG7[28177:3062528944]: SSL state (accept): before/accept initialization 2004.08.17 11:03:12 LOG7[28177:3062528944]: waitforsocket: FD=7, DIR=read 2004.08.17 11:03:12 LOG7[28177:3062528944]: waitforsocket: ok 2004.08.17 11:03:12 LOG7[28177:3062528944]: SSL state (accept): SSLv3 read client hello A 2004.08.17 11:03:12 LOG7[28177:3062528944]: SSL state (accept): SSLv3 write server hello A 2004.08.17 11:03:12 LOG7[28177:3062528944]: SSL state (accept): SSLv3 write certificate A 2004.08.17 11:03:12 LOG7[28177:3062528944]: SSL state (accept): SSLv3 write server done A 2004.08.17 11:03:12 LOG7[28177:3062528944]: SSL state (accept): SSLv3 flush data 2004.08.17 11:03:12 LOG7[28177:3062528944]: waitforsocket: FD=7, DIR=read 2004.08.17 11:03:12 LOG7[28177:3062528944]: waitforsocket: ok 2004.08.17 11:03:12 LOG7[28177:3062528944]: SSL state (accept): SSLv3 read client key exchange A 2004.08.17 11:03:12 LOG7[28177:3062528944]: SSL state (accept): SSLv3 read finished A 2004.08.17 11:03:12 LOG7[28177:3062528944]: SSL state (accept): SSLv3 write change cipher spec A 2004.08.17 11:03:12 LOG7[28177:3062528944]: SSL state (accept): SSLv3 write finished A 2004.08.17 11:03:12 LOG7[28177:3062528944]: SSL state (accept): SSLv3 flush data 2004.08.17 11:03:12 LOG7[28177:3062528944]: 2 items in the session cache 2004.08.17 11:03:12 LOG7[28177:3062528944]: 0 client connects (SSL_connect()) 2004.08.17 11:03:12 LOG7[28177:3062528944]: 0 client connects that finished 2004.08.17 11:03:12 LOG7[28177:3062528944]: 0 client renegotiatations requested 2004.08.17 11:03:12 LOG7[28177:3062528944]: 18 server connects (SSL_accept()) 2004.08.17 11:03:12 LOG7[28177:3062528944]: 10 server connects that finished 2004.08.17 11:03:12 LOG7[28177:3062528944]: 0 server renegotiatiations requested 2004.08.17 11:03:12 LOG7[28177:3062528944]: 2 session cache hits 2004.08.17 11:03:12 LOG7[28177:3062528944]: 0 session cache misses 2004.08.17 11:03:12 LOG7[28177:3062528944]: 6 session cache timeouts 2004.08.17 11:03:12 LOG6[28177:3062528944]: Negotiated ciphers: AES256-SHA SSLv3 Kx=RSA Au=RSA Enc=AES(256) Mac=SHA1 2004.08.17 11:03:12 LOG7[28177:3062528944]: FD 8 in non-blocking mode 2004.08.17 11:03:12 LOG7[28177:3062528944]: 55555 connecting 192.168.20.76:4242 2004.08.17 11:03:12 LOG7[28177:3062528944]: remote connect #1: EINPROGRESS: retrying 2004.08.17 11:03:12 LOG7[28177:3062528944]: waitforsocket: FD=8, DIR=write 2004.08.17 11:03:12 LOG7[28177:3062528944]: waitforsocket: ok 2004.08.17 11:03:12 LOG7[28177:3062528944]: Remote FD=8 initialized 2004.08.17 11:03:12 LOG7[28177:3062528944]: Socket closed on read 2004.08.17 11:03:12 LOG7[28177:3062528944]: SSL alert (write): warning: close notify 2004.08.17 11:03:12 LOG7[28177:3062528944]: SSL write shutdown (output buffer empty) 2004.08.17 11:03:12 LOG7[28177:3062528944]: SSL alert (read): warning: close notify 2004.08.17 11:03:12 LOG7[28177:3062528944]: SSL closed on SSL_read 2004.08.17 11:03:12 LOG7[28177:3062528944]: Socket write shutdown (output buffer empty) 2004.08.17 11:03:12 LOG5[28177:3062528944]: Connection closed: 13 bytes sent to SSL, 110 bytes sent to socket 2004.08.17 11:03:12 LOG7[28177:3062528944]: 55555 finished (0 left)
-------------------------------------------------------------------------------------------------------------------
My client stunnel.conf:
cert=stunnel.pem client=yes debug=7 [55555] accept=localhost:55555 connect=192.168.20.76:55555 - eof -
My server stunnel.conf:
cert=stunnel.pem debug=7 output=stunnel.err [55555] accept=192.168.20.76:55555 connect=192.168.20.76:4242 - eof -
-- Using Opera's revolutionary e-mail client: http://www.opera.com/m2/
participants (2)
-
Charles A. Monteiro -
david-e.hansen＠ubs.com