[stunnel-users] stunnel + qmail-pop3d hang
Włodek
ratel at post.pl
Tue Oct 25 13:26:43 CEST 2005
Hi,
I'm having a little problem with retrieving messages from my
ssl-enabled pop3 server.
I use : stunnel 4.12, openssl 0.9.8a. The problem is : when I
connect to my pop3s
service(from a remote machine) - I accept certificate and
authenticate easily, but the
process hangs(I've shown in the log when it happens) when I try to
recieve mail.
Now, when I try to recieve some tiny messages - up to ~15KB
everything goes well, but
if a message is larger - process hangs and from that point I cannot
retrieve mail at all.
When I switch to pop3 (runs on separate port) problem disappears.
Additionally when I
connect from localhost no problem occurs (!). My observations: when
connecting by s_client -
the moment when the process hangs corresponds to the moment of
trying to
retrieve a message (retr <message_no>). I've tested it on various
MUA's : Linux:Mozilla Mail,
Windoze:Opera Mail, Thunderbird, M$ Outlook and it's now clear that
it's a server problem.
below I post my configuration/logs:
1.my /service/qmail-pop3sd/run file looks like this:
-CUT-
pop3conf=/etc/stunnel/pop3s.conf
exec /usr/local/bin/softlimit -m 10000000 \
/usr/local/bin/tcpserver -vRH -l 0 0 995 \
/usr/local/sbin/stunnel $pop3conf 2>&1
-CUT-
2. /etc/stunnel/pop3s.conf:
-CUT-
cert = /etc/stunnel/stunnel_mail.pem
client = no
#output = /var/log/stunnel.log
debug = 7
foreground = yes
exec = /var/qmail/bin/qmail-popup
execargs = /var/qmail/bin/qmail-popup mail.myserver.com
/bin/checkpassword /var/qmail/bin/qmail-pop3d Maildir 2>&1
-CUT-
3. sample openssl s_client login:
-CUT-
root at server:~# openssl s_client -connect myserver.com:pop3s
CONNECTED(00000003)
---
[...some cert details...]
---
New, TLSv1/SSLv3, Cipher is DHE-RSA-AES256-SHA
Server public key is 1024 bit
Compression: NONE
Expansion: NONE
SSL-Session:
Protocol : TLSv1
Cipher : DHE-RSA-AES256-SHA
Session-ID:
0A9A22285A5ADA25637D9019F51F596F741DAF86636247B3FE49E0AE823030E9
Session-ID-ctx:
Master-Key:
2918CD1DC46E77FFE43665EC9625A0CF8D8F8C8DCB07F481CBB68376297188E80E5D94146D2B359211BE12
\
5317F498C7 Key-Arg : None
Start Time: 1129661468
Timeout : 300 (sec)
Verify return code: 18 (self signed certificate)
---
+OK <31383.1129661468 at mail.myserver.com>
user [username]
+OK
pass [my_password]
+OK
list
1 18467
2 5075
3 2528
4 8766
5 2538
6 14447
7 3813
8 9361
9 8179
10 8621
.
retr 2
[HANGS NOW!]
-CUT-
4.log: pop3sd/current
-CUT-----------------------
@40000000435505b02eedf82c tcpserver: status: 1/40
@40000000435505b02eef4434 tcpserver: pid 6714 from 62.111.159.222
@40000000435505b02eefc904 tcpserver: ok 6714 \
0:10.0.251.3:995 :62.111.159.222::40160
@40000000435505b02f1b036c 2005.10.18 16:24:38 LOG5[6714:16384]: stunnel
4.12 on i686-pc-linux-gnu PTHREAD+POLL+IPv4+LIBWRAP with OpenSSL 0.9.8a
11 Oct 2005
@40000000435505b02f8d550c 2005.10.18 16:24:38 LOG7[6714:16384]: Snagged
64 random bytes from /dev/urandom
@40000000435505b02f903b3c 2005.10.18 16:24:38 LOG7[6714:16384]:
RAND_status claims sufficient entropy for the PRNG
@40000000435505b02f90d394 2005.10.18 16:24:38 LOG6[6714:16384]: PRNG
seeded successfully
@40000000435505b02f98af4c 2005.10.18 16:24:38 LOG7[6714:16384]: Using
Diffie-Hellman parameters from /etc/stunnel/stunnel_mail.pem
@40000000435505b02fbbdf1c 2005.10.18 16:24:38 LOG6[6714:16384]:
Diffie-Hellman initialized with 512 bit key
@40000000435505b02fc3d62c 2005.10.18 16:24:38 LOG7[6714:16384]:
Certificate: /etc/stunnel/stunnel_mail.pem
@40000000435505b02fc47654 2005.10.18 16:24:38 LOG7[6714:16384]: Key
file: /etc/stunnel/stunnel_mail.pem
@40000000435505b02fc9c5b4 2005.10.18 16:24:38 LOG7[6714:16384]: stunnel
started
@40000000435505b02fcac784 2005.10.18 16:24:38 LOG7[6714:16384]: FD 0 in
non-blocking mode
@40000000435505b02fcb5bf4 2005.10.18 16:24:38 LOG7[6714:16384]: FD 1 in
non-blocking mode
@40000000435505b02fd02684 2005.10.18 16:24:38 LOG5[6714:16384]: stunnel
connected from 62.111.159.222:40160
@40000000435505b02fd4f8e4 2005.10.18 16:24:38 LOG7[6714:16384]: SSL
state (accept): before/accept initialization
@40000000435505b02fda01f4 2005.10.18 16:24:38 LOG7[6714:16384]: SSL
state (accept): SSLv3 read client hello A
@40000000435505b02fdb6954 2005.10.18 16:24:38 LOG7[6714:16384]: SSL
state (accept): SSLv3 write server hello A
@40000000435505b02fde5f24 2005.10.18 16:24:38 LOG7[6714:16384]: SSL
state (accept): SSLv3 write certificate A
@40000000435505b030301cec 2005.10.18 16:24:38 LOG7[6714:16384]: SSL
state (accept): SSLv3 write key exchange A
@40000000435505b03030efdc 2005.10.18 16:24:38 LOG7[6714:16384]: SSL
state (accept): SSLv3 write server done A
@40000000435505b03032cc6c 2005.10.18 16:24:38 LOG7[6714:16384]: SSL
state (accept): SSLv3 flush data
@40000000435505b031bac814 2005.10.18 16:24:38 LOG7[6714:16384]: SSL
state (accept): SSLv3 read client key exchange A
@40000000435505b031bf3cb4 2005.10.18 16:24:38 LOG7[6714:16384]: SSL
state (accept): SSLv3 read finished A
@40000000435505b031c03a9c 2005.10.18 16:24:38 LOG7[6714:16384]: SSL
state (accept): SSLv3 write change cipher spec A
@40000000435505b031c1fbd4 2005.10.18 16:24:38 LOG7[6714:16384]: SSL
state (accept): SSLv3 write finished A
@40000000435505b031c37aa4 2005.10.18 16:24:38 LOG7[6714:16384]: SSL
state (accept): SSLv3 flush data
@40000000435505b031c52c3c 2005.10.18 16:24:38 LOG7[6714:16384]: 1
items in the session cache
@40000000435505b031c5c0ac 2005.10.18 16:24:38 LOG7[6714:16384]: 0
client connects (SSL_connect())
@40000000435505b031c63dac 2005.10.18 16:24:38 LOG7[6714:16384]: 0
client connects that finished
@40000000435505b031c6baac 2005.10.18 16:24:38 LOG7[6714:16384]: 0
client renegotiatations requested
@40000000435505b031c7956c 2005.10.18 16:24:38 LOG7[6714:16384]: 1
server connects (SSL_accept())
@40000000435505b031c81a3c 2005.10.18 16:24:38 LOG7[6714:16384]: 1
server connects that finished
@40000000435505b031c8973c 2005.10.18 16:24:38 LOG7[6714:16384]: 0
server renegotiatiations requested
@40000000435505b031c9143c 2005.10.18 16:24:38 LOG7[6714:16384]: 0
session cache hits
@40000000435505b031c98d54 2005.10.18 16:24:38 LOG7[6714:16384]: 1
session cache misses
@40000000435505b031ca0a54 2005.10.18 16:24:38 LOG7[6714:16384]: 0
session cache timeouts
@40000000435505b031cab634 2005.10.18 16:24:38 LOG6[6714:16384]: SSL
accepted: new session negotiated
@40000000435505b031cbcb8c 2005.10.18 16:24:38 LOG6[6714:16384]:
Negotiated ciphers: DHE-RSA-AES256-SHA SSLv3 Kx=DH Au=RSA
Enc=AES(256) Mac=SHA1
@40000000435505b031d4188c 2005.10.18 16:24:38 LOG6[6714:16384]: Local
mode child started (PID=6715)
@40000000435505b031d506d4 2005.10.18 16:24:38 LOG7[6714:16384]: Remote
FD=5 initialized
@40000000435505b10925453c 2005.10.18 16:24:39 LOG7[6714:16384]:
SSL_write returned WANT_WRITE: retrying
@40000000435505b109264edc 2005.10.18 16:24:39 LOG7[6714:16384]: SSL_read
returned WANT_READ: retrying
--------------at this point it hangs-----------------
-after canceling task in my MUA(Mozilla Mail, etc.) stunnel unhangs but
no message is downloaded---
@40000000435505b51d17f5bc 2005.10.18 16:24:43 LOG7[6714:16384]: SSL
alert (read): warning: close notify
@40000000435505b51d18cc94 2005.10.18 16:24:43 LOG7[6714:16384]: SSL
closed on SSL_read
@40000000435505b51d19554c 2005.10.18 16:24:43 LOG7[6714:16384]: Socket
write shutdown
@40000000435505b51d1b58ec 2005.10.18 16:24:43 LOG7[6714:16384]: SSL
write shutdown
@40000000435505b51d1d21f4 2005.10.18 16:24:43 LOG7[6714:16384]: SSL
alert (write): warning: close notify
@40000000435505b51d1db664 2005.10.18 16:24:43 LOG6[6714:16384]:
SSL_shutdown successfully sent close_notify
@40000000435505b51d209c94 2005.10.18 16:24:43 LOG5[6714:16384]:
Connection closed: 17538 bytes sent to SSL, 59 bytes sent to socket
@40000000435505b51d240794 2005.10.18 16:24:43 LOG7[6714:16384]: stunnel
finished (0 left)
@40000000435505b51d2be734 tcpserver: end 6714 status 0
@40000000435505b51d2c44f4 tcpserver: status: 0/40
-CUT-------
thanks in advance for help
Wlodek
More information about the stunnel-users
mailing list