Hi folks,
I use stunnel-4.12 with openssl-0.9.7g to tunnel my CVS-pserver protocols. I have set up the local stunnel client to listen to port 22400 and to forward any connections on it to the cvs server that has the server side stunnel listening on port 22401 forwarding connections to the cvs-pserver on port 2401.
Having set up thus, I can do a cvs login just fine. I can watch the negotiation happening using tcpdump. However when I try to check out a module from the repository, I see some files coming through but only to eventually hang. If I <Ctrl C> and try again, more files come in but hangs before the transaction is complete. I have to do this several time in order to download all the files to my local workspace.
Upon checking the logs, I find that the hang occurs immediately after the message:
2005.10.28 14:21:53 LOG7[15095:67]: SSL_read returned WANT_READ: retrying 2005.10.28 14:21:53 LOG7[15095:67]: SSL_write returned WANT_WRITE: retrying 2005.10.28 14:21:53 LOG7[15095:67]: SSL_read returned WANT_READ: retrying
I have included a snippet of the log file for reference. I have also included my stunnel.conf file. Sorry for the voluminous output. Can some one help me here? Thanks in advance.
-ZZ ===============================STUNNEL.LOG================================== The full log file reads:
2005.10.28 14:20:44 LOG6[15095:64]: SSL accepted: previous session reused 2005.10.28 14:20:44 LOG7[15095:64]: FD 1 in non-blocking mode 2005.10.28 14:20:44 LOG7[15095:64]: smd-pserver connecting 127.0.0.1:2401 2005.10.28 14:20:44 LOG7[15095:64]: Remote FD=1 initialized 2005.10.28 14:20:44 LOG7[15095:64]: SSL_read returned WANT_READ: retrying 2005.10.28 14:20:44 LOG7[15095:64]: SSL_write returned WANT_WRITE: retrying 2005.10.28 14:20:44 LOG7[15095:64]: SSL_read returned WANT_READ: retrying 2005.10.28 14:20:50 LOG7[15095:64]: SSL alert (read): warning: close notify 2005.10.28 14:20:50 LOG7[15095:64]: SSL closed on SSL_read 2005.10.28 14:20:50 LOG7[15095:64]: Socket write shutdown 2005.10.28 14:20:50 LOG7[15095:64]: SSL write shutdown 2005.10.28 14:20:50 LOG7[15095:64]: SSL alert (write): warning: close notify 2005.10.28 14:20:50 LOG6[15095:64]: SSL_shutdown successfully sent close_notify 2005.10.28 14:20:50 LOG5[15095:64]: Connection closed: 73224 bytes sent to SSL, 4724 bytes sent to socket 2005.10.28 14:20:50 LOG7[15095:64]: smd-pserver finished (0 left) 2005.10.28 14:20:50 LOG5[15095:64]: stack_info: size=65536, current=5004 (7%), maximum=5004 (7%) 2005.10.28 14:20:50 LOG7[15095:64]: Context 64 closed 2005.10.28 14:20:51 LOG7[15095:1]: Context set: 64 (dropped) -> 1 2005.10.28 14:20:51 LOG7[15095:1]: Current context: 1 2005.10.28 14:20:51 LOG7[15095:1]: Releasing context 64 2005.10.28 14:20:51 LOG7[15095:1]: smd-pserver accepted FD=0 from 171.65.79.143:65521 2005.10.28 14:20:51 LOG7[15095:1]: Creating a new context 2005.10.28 14:20:51 LOG7[15095:1]: Context 65 created 2005.10.28 14:20:51 LOG7[15095:65]: Context swap: 1 -> 65 2005.10.28 14:20:51 LOG7[15095:65]: smd-pserver started 2005.10.28 14:20:51 LOG7[15095:65]: FD 0 in non-blocking mode 2005.10.28 14:20:51 LOG5[15095:65]: smd-pserver connected from 171.65.79.143:65521 2005.10.28 14:20:51 LOG7[15095:65]: SSL state (accept): before/accept initialization 2005.10.28 14:20:51 LOG7[15095:65]: SSL state (accept): SSLv3 read client hello A 2005.10.28 14:20:51 LOG7[15095:65]: SSL state (accept): SSLv3 write server hello A 2005.10.28 14:20:51 LOG7[15095:65]: SSL state (accept): SSLv3 write change cipher spec A 2005.10.28 14:20:51 LOG7[15095:65]: SSL state (accept): SSLv3 write finished A 2005.10.28 14:20:51 LOG7[15095:65]: SSL state (accept): SSLv3 flush data 2005.10.28 14:20:51 LOG7[15095:65]: SSL state (accept): SSLv3 read finished A 2005.10.28 14:20:51 LOG7[15095:65]: 6 items in the session cache 2005.10.28 14:20:51 LOG7[15095:65]: 0 client connects (SSL_connect()) 2005.10.28 14:20:51 LOG7[15095:65]: 0 client connects that finished 2005.10.28 14:20:51 LOG7[15095:65]: 0 client renegotiatations requested 2005.10.28 14:20:51 LOG7[15095:65]: 64 server connects (SSL_accept()) 2005.10.28 14:20:51 LOG7[15095:65]: 55 server connects that finished 2005.10.28 14:20:51 LOG7[15095:65]: 0 server renegotiatiations requested 2005.10.28 14:20:51 LOG7[15095:65]: 38 session cache hits 2005.10.28 14:20:51 LOG7[15095:65]: 0 session cache misses 2005.10.28 14:20:51 LOG7[15095:65]: 11 session cache timeouts 2005.10.28 14:20:51 LOG6[15095:65]: SSL accepted: previous session reused 2005.10.28 14:20:51 LOG7[15095:65]: FD 1 in non-blocking mode 2005.10.28 14:20:51 LOG7[15095:65]: smd-pserver connecting 127.0.0.1:2401 2005.10.28 14:20:51 LOG7[15095:65]: Remote FD=1 initialized 2005.10.28 14:20:51 LOG7[15095:65]: SSL_read returned WANT_READ: retrying 2005.10.28 14:20:51 LOG7[15095:65]: SSL_write returned WANT_WRITE: retrying 2005.10.28 14:20:51 LOG7[15095:65]: SSL_read returned WANT_READ: retrying 2005.10.28 14:20:57 LOG7[15095:65]: SSL alert (read): warning: close notify 2005.10.28 14:20:57 LOG7[15095:65]: SSL closed on SSL_read 2005.10.28 14:20:57 LOG7[15095:65]: Socket write shutdown 2005.10.28 14:20:57 LOG7[15095:65]: SSL write shutdown 2005.10.28 14:20:57 LOG7[15095:65]: SSL alert (write): warning: close notify 2005.10.28 14:20:57 LOG6[15095:65]: SSL_shutdown successfully sent close_notify 2005.10.28 14:20:57 LOG5[15095:65]: Connection closed: 73224 bytes sent to SSL, 4724 bytes sent to socket 2005.10.28 14:20:57 LOG7[15095:65]: smd-pserver finished (0 left) 2005.10.28 14:20:57 LOG5[15095:65]: stack_info: size=65536, current=5004 (7%), maximum=5004 (7%) 2005.10.28 14:20:57 LOG7[15095:65]: Context 65 closed 2005.10.28 14:20:58 LOG7[15095:1]: Context set: 65 (dropped) -> 1 2005.10.28 14:20:58 LOG7[15095:1]: Current context: 1 2005.10.28 14:20:58 LOG7[15095:1]: Releasing context 65 2005.10.28 14:20:58 LOG7[15095:1]: smd-pserver accepted FD=0 from 171.65.79.143:65523 2005.10.28 14:20:58 LOG7[15095:1]: Creating a new context 2005.10.28 14:20:58 LOG7[15095:1]: Context 66 created 2005.10.28 14:20:58 LOG7[15095:66]: Context swap: 1 -> 66 2005.10.28 14:20:58 LOG7[15095:66]: smd-pserver started 2005.10.28 14:20:58 LOG7[15095:66]: FD 0 in non-blocking mode 2005.10.28 14:20:58 LOG5[15095:66]: smd-pserver connected from 171.65.79.143:65523 2005.10.28 14:20:58 LOG7[15095:66]: SSL state (accept): before/accept initialization 2005.10.28 14:20:58 LOG7[15095:66]: SSL state (accept): SSLv3 read client hello A 2005.10.28 14:20:58 LOG7[15095:66]: SSL state (accept): SSLv3 write server hello A 2005.10.28 14:20:58 LOG7[15095:66]: SSL state (accept): SSLv3 write change cipher spec A 2005.10.28 14:20:58 LOG7[15095:66]: SSL state (accept): SSLv3 write finished A 2005.10.28 14:20:58 LOG7[15095:66]: SSL state (accept): SSLv3 flush data 2005.10.28 14:20:58 LOG7[15095:66]: SSL state (accept): SSLv3 read finished A 2005.10.28 14:20:58 LOG7[15095:66]: 6 items in the session cache 2005.10.28 14:20:58 LOG7[15095:66]: 0 client connects (SSL_connect()) 2005.10.28 14:20:58 LOG7[15095:66]: 0 client connects that finished 2005.10.28 14:20:58 LOG7[15095:66]: 0 client renegotiatations requested 2005.10.28 14:20:58 LOG7[15095:66]: 65 server connects (SSL_accept()) 2005.10.28 14:20:58 LOG7[15095:66]: 56 server connects that finished 2005.10.28 14:20:58 LOG7[15095:66]: 0 server renegotiatiations requested 2005.10.28 14:20:58 LOG7[15095:66]: 39 session cache hits 2005.10.28 14:20:58 LOG7[15095:66]: 0 session cache misses 2005.10.28 14:20:58 LOG7[15095:66]: 11 session cache timeouts 2005.10.28 14:20:58 LOG6[15095:66]: SSL accepted: previous session reused 2005.10.28 14:20:58 LOG7[15095:66]: FD 1 in non-blocking mode 2005.10.28 14:20:58 LOG7[15095:66]: smd-pserver connecting 127.0.0.1:2401 2005.10.28 14:20:58 LOG7[15095:66]: Remote FD=1 initialized 2005.10.28 14:20:58 LOG7[15095:66]: SSL_read returned WANT_READ: retrying 2005.10.28 14:20:58 LOG7[15095:66]: SSL_write returned WANT_WRITE: retrying 2005.10.28 14:20:58 LOG7[15095:66]: SSL_read returned WANT_READ: retrying 2005.10.28 14:21:50 LOG7[15095:66]: SSL alert (read): warning: close notify 2005.10.28 14:21:50 LOG7[15095:66]: SSL closed on SSL_read 2005.10.28 14:21:50 LOG7[15095:66]: Socket write shutdown 2005.10.28 14:21:50 LOG7[15095:66]: SSL write shutdown 2005.10.28 14:21:50 LOG7[15095:66]: SSL alert (write): warning: close notify 2005.10.28 14:21:50 LOG6[15095:66]: SSL_shutdown successfully sent close_notify 2005.10.28 14:21:50 LOG5[15095:66]: Connection closed: 73224 bytes sent to SSL, 4724 bytes sent to socket 2005.10.28 14:21:50 LOG7[15095:66]: smd-pserver finished (0 left) 2005.10.28 14:21:50 LOG5[15095:66]: stack_info: size=65536, current=5004 (7%), maximum=5004 (7%) 2005.10.28 14:21:50 LOG7[15095:66]: Context 66 closed 2005.10.28 14:21:52 LOG7[15095:1]: Context set: 66 (dropped) -> 1 2005.10.28 14:21:52 LOG7[15095:1]: Current context: 1 2005.10.28 14:21:52 LOG7[15095:1]: Releasing context 66 2005.10.28 14:21:52 LOG7[15095:1]: smd-pserver accepted FD=0 from 171.65.79.143:65525 2005.10.28 14:21:52 LOG7[15095:1]: Creating a new context 2005.10.28 14:21:52 LOG7[15095:1]: Context 67 created 2005.10.28 14:21:52 LOG7[15095:67]: Context swap: 1 -> 67 2005.10.28 14:21:52 LOG7[15095:67]: smd-pserver started 2005.10.28 14:21:52 LOG7[15095:67]: FD 0 in non-blocking mode 2005.10.28 14:21:52 LOG5[15095:67]: smd-pserver connected from 171.65.79.143:65525 2005.10.28 14:21:52 LOG7[15095:67]: SSL state (accept): before/accept initialization 2005.10.28 14:21:52 LOG7[15095:67]: SSL state (accept): SSLv3 read client hello A 2005.10.28 14:21:52 LOG7[15095:67]: SSL state (accept): SSLv3 write server hello A 2005.10.28 14:21:52 LOG7[15095:67]: SSL state (accept): SSLv3 write change cipher spec A 2005.10.28 14:21:52 LOG7[15095:67]: SSL state (accept): SSLv3 write finished A 2005.10.28 14:21:52 LOG7[15095:67]: SSL state (accept): SSLv3 flush data 2005.10.28 14:21:52 LOG7[15095:67]: SSL state (accept): SSLv3 read finished A 2005.10.28 14:21:52 LOG7[15095:67]: 6 items in the session cache 2005.10.28 14:21:52 LOG7[15095:67]: 0 client connects (SSL_connect()) 2005.10.28 14:21:52 LOG7[15095:67]: 0 client connects that finished 2005.10.28 14:21:52 LOG7[15095:67]: 0 client renegotiatations requested 2005.10.28 14:21:52 LOG7[15095:67]: 66 server connects (SSL_accept()) 2005.10.28 14:21:52 LOG7[15095:67]: 57 server connects that finished 2005.10.28 14:21:52 LOG7[15095:67]: 0 server renegotiatiations requested 2005.10.28 14:21:52 LOG7[15095:67]: 40 session cache hits 2005.10.28 14:21:52 LOG7[15095:67]: 0 session cache misses 2005.10.28 14:21:52 LOG7[15095:67]: 11 session cache timeouts 2005.10.28 14:21:52 LOG6[15095:67]: SSL accepted: previous session reused 2005.10.28 14:21:52 LOG7[15095:67]: FD 1 in non-blocking mode 2005.10.28 14:21:52 LOG7[15095:67]: smd-pserver connecting 127.0.0.1:2401 2005.10.28 14:21:52 LOG7[15095:67]: Remote FD=1 initialized 2005.10.28 14:21:53 LOG7[15095:67]: SSL_read returned WANT_READ: retrying 2005.10.28 14:21:53 LOG7[15095:67]: SSL_write returned WANT_WRITE: retrying 2005.10.28 14:21:53 LOG7[15095:67]: SSL_read returned WANT_READ: retrying ========================================================================== =========================STUNNEL.CONF======================================
; Sample stunnel configuration file by Michal Trojnara 2002-2005 ; Some options used here may not be adequate for your particular configuration ; Please make sure you understand them (especially the effect of chroot jail) ;Delay DNS Lookups delay = yes ; Certificate/key is needed in server mode and optional in client mode cert = /tools/stunnel/4.12/etc/stunnel/stunnel.pem ;key = /tools/stunnel/4.12/etc/stunnel/mail.pem
; Some security enhancements for UNIX systems - comment them out on Win32 chroot = /tools/stunnel/4.12/var/stunnel/ setuid = cvsadmin setgid = cvs ; PID is created inside chroot jail pid = /stunnel.pid
; Some performance tunings socket = l:TCP_NODELAY=1 socket = r:TCP_NODELAY=1 ;compression = rle
; Workaround for Eudora bug ;options = DONT_INSERT_EMPTY_FRAGMENTS
; Authentication stuff ;verify = 2 ; Don't forget to c_rehash CApath; CApath is located inside chroot jail: ;CApath = /certs ; It's often easier to use CAfile: ;CAfile = /tools/stunnel/4.12/etc/stunnel/certs.pem ; Don't forget to c_rehash CRLpath; CRLpath is located inside chroot jail: ;CRLpath = /crls ; Alternatively you can use CRLfile: ;CRLfile = /tools/stunnel/4.12/etc/stunnel/crls.pem
; Some debugging stuff useful for troubleshooting debug = 7 output = /tools/stunnel/current/var/stunnel/stunnel.log
; Use it for client mode ;client = yes
; Service-level configuration
;[pop3s] ;accept = 995 ;connect = 110
;[imaps] ;accept = 993 ;connect = 143
;[ssmtp] ;accept = 465 ;connect = 25
[pserver] accept = 22401 connect = 2401 TIMEOUTclose = 30
; vim:ft=dosini
Zachariah,
On Fri, 28 Oct 2005, Zachariah K Zachariah wrote:
Hi folks,
I use stunnel-4.12 with openssl-0.9.7g
[...]
2005.10.28 14:21:53 LOG7[15095:67]: SSL_read returned WANT_READ: retrying 2005.10.28 14:21:53 LOG7[15095:67]: SSL_write returned WANT_WRITE: retrying 2005.10.28 14:21:53 LOG7[15095:67]: SSL_read returned WANT_READ: retrying
[...]
A number of people, myself included, experienced problems with 4.12 (and 4.13) when trying to move non-trivial amounts of data around.
A fix was provided in 4.14b1 - worked for me, and for others, and I haven't yet seen anyone say it doesn't work for them. So ... time to upgrade :-)
HTH, Richard
Whew! Thanks Richard for the pointer. It works like a charm in 4.14.
--Zachairah
Quoting "Richard.Hall" Richard.Hall@ingenta.com:
Zachariah,
On Fri, 28 Oct 2005, Zachariah K Zachariah wrote:
Hi folks,
I use stunnel-4.12 with openssl-0.9.7g
[...]
2005.10.28 14:21:53 LOG7[15095:67]: SSL_read returned WANT_READ:
retrying
2005.10.28 14:21:53 LOG7[15095:67]: SSL_write returned WANT_WRITE:
retrying
2005.10.28 14:21:53 LOG7[15095:67]: SSL_read returned WANT_READ:
retrying [...]
A number of people, myself included, experienced problems with 4.12 (and 4.13) when trying to move non-trivial amounts of data around.
A fix was provided in 4.14b1 - worked for me, and for others, and I haven't yet seen anyone say it doesn't work for them. So ... time to upgrade :-)
HTH, Richard
Yes, this also worked for me, I am running RSYNC over stunnel and had the same problem. 4.14 fixed it :D
Jeremy
Zachariah K Zachariah wrote:
Whew! Thanks Richard for the pointer. It works like a charm in 4.14.
--Zachairah
Quoting "Richard.Hall" Richard.Hall@ingenta.com:
Zachariah,
On Fri, 28 Oct 2005, Zachariah K Zachariah wrote:
Hi folks,
I use stunnel-4.12 with openssl-0.9.7g
[...]
2005.10.28 14:21:53 LOG7[15095:67]: SSL_read returned WANT_READ:
retrying
2005.10.28 14:21:53 LOG7[15095:67]: SSL_write returned WANT_WRITE:
retrying
2005.10.28 14:21:53 LOG7[15095:67]: SSL_read returned WANT_READ:
retrying [...]
A number of people, myself included, experienced problems with 4.12 (and 4.13) when trying to move non-trivial amounts of data around.
A fix was provided in 4.14b1 - worked for me, and for others, and I haven't yet seen anyone say it doesn't work for them. So ... time to upgrade :-)
HTH, Richard
stunnel-users mailing list stunnel-users@mirt.net http://stunnel.mirt.net/mailman/listinfo/stunnel-users