[stunnel-users] Stunnel dropping data on binary uploads from most browsers.

• Previous message (by thread): [stunnel-users] stunnel daemon mode
• Next message (by thread): [stunnel-users] Stunnel dropping data on binary uploads from most browsers.
• Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]

All,

I'm hoping that someone can assist with this. 

I'm using Stunnel on 2 different systems: Mac and FC 13 to front-end my web server for a custom database system. It works flawlessly except for uploading large binary files.

The problem comes when trying to upload say a 2.5MB image file. The number of bytes actually transferred to the exec program is usually under 1K or right at about 33K. Using Firefox on Windows works all the time. I can observe the transfer by watching the stunnel.log file. When the data is piped into the openSSL engine, the number of bytes written to socket is being picked up by the exec program and processed so the loss is between the browser and the output side of Stunnel. 

The message itself is a multi-part message that is not mime-encoded. The part with the image is set in the boundary properly and contains the JPEG binary. (Thanks to HTTPwatch!) 

My Stunnel Version is: 

[root at linux log]# stunnel -version 
stunnel 4.33 on i386-redhat-linux-gnu with OpenSSL 1.0.0a-fips 1 Jun 
2010 
Threading:PTHREAD SSL:ENGINE Sockets:POLL,IPv6 Auth:LIBWRAP 

Global options 
debug           = daemon.notice 
pid             = /var/run/stunnel.pid 
RNDbytes        = 64 
RNDfile         = /dev/urandom 
RNDoverwrite    = yes 

Service-level options 
cert            = /etc/stunnel/stunnel.pem 
ciphers         = ALL:!aNULL:!eNULL:!SSLv2 
session         = 300 seconds 
stack           = 65536 bytes 
sslVersion      = SSLv3 for client, all for server 
TIMEOUTbusy     = 300 seconds 
TIMEOUTclose    = 60 seconds 
TIMEOUTconnect  = 10 seconds 
TIMEOUTidle     = 43200 seconds 
verify          = none 

My configuration file on the Linux box is: 

cert = /etc/stunnel/server.crt 
key = /etc/stunnel/server.key 
debug = 7 
output = /var/log/stunnel.log 
;socket = l:SO_LINGER=1:60 
;socket = r:TCP_NODELAY=1 
client = no 
sslVersion = SSLv3 
[https] 
libwrap = no 
accept = 443 
exec = /usr/qmsys/bin/qm 
execargs = /usr/qmsys/bin/qm -b7 -quiet -aPAVUK "P.HTTP" 
options = DONT_INSERT_EMPTY_FRAGMENTS 
TIMEOUTidle = 30 
TIMEOUTbusy = 5 
TIMEOUTclose = 0 

*** A RANDOM SUCCESSFUL TRANSFER *** 
2010.10.15 10:03:12 LOG7[946:3078133552]: Service https accepted FD=0 from 24.171.161.99:1998 
2010.10.15 10:03:12 LOG7[946:3078241136]: Service https started 
2010.10.15 10:03:12 LOG7[946:3078241136]: FD=0 in non-blocking mode 
2010.10.15 10:03:12 LOG5[946:3078241136]: Service https accepted connection from 24.171.161.99:1998 
2010.10.15 10:03:12 LOG7[946:3078241136]: SSL state (accept): before accept initialization 
2010.10.15 10:03:12 LOG7[946:3078241136]: SSL state (accept): SSLv3  read client hello A 
2010.10.15 10:03:12 LOG7[946:3078241136]: SSL state (accept): SSLv3 write server hello A 
2010.10.15 10:03:12 LOG7[946:3078241136]: SSL state (accept): SSLv3 write change cipher spec A 
2010.10.15 10:03:12 LOG7[946:3078241136]: SSL state (accept): SSLv3 write finished A 
2010.10.15 10:03:12 LOG7[946:3078241136]: SSL state (accept): SSLv3 flush data 
2010.10.15 10:03:12 LOG7[946:3078241136]: SSL state (accept): SSLv3 read finished A 
2010.10.15 10:03:12 LOG7[946:3078241136]:    8 items in the session cache 
2010.10.15 10:03:12 LOG7[946:3078241136]:    0 client connects (SSL_connect()) 
2010.10.15 10:03:12 LOG7[946:3078241136]:    0 client connects that finished 
2010.10.15 10:03:12 LOG7[946:3078241136]:    0 client renegotiations requested 
2010.10.15 10:03:12 LOG7[946:3078241136]:   35 server connects (SSL_accept()) 
2010.10.15 10:03:12 LOG7[946:3078241136]:   35 server connects that finished 
2010.10.15 10:03:12 LOG7[946:3078241136]:    0 server renegotiations requested 
2010.10.15 10:03:12 LOG7[946:3078241136]:   27 session cache hits 

2010.10.15 10:03:12 LOG7[946:3078241136]:    0 external session cache hits 
2010.10.15 10:03:12 LOG7[946:3078241136]:    0 session cache misses 
2010.10.15 10:03:12 LOG7[946:3078241136]:    0 session cache timeouts 
2010.10.15 10:03:12 LOG6[946:3078241136]: SSL accepted: previous session reused 
2010.10.15 10:03:12 LOG6[946:3078241136]: Local mode child started (PID=1179) 
2010.10.15 10:03:12 LOG7[946:3078241136]: Remote FD=13 initialized 
2010.10.15 10:03:13 LOG7[946:3078241136]: Socket closed on read 
2010.10.15 10:03:13 LOG7[946:3078241136]: SSL write shutdown 
2010.10.15 10:03:13 LOG7[946:3078241136]: SSL alert (write): warning: close notify 
2010.10.15 10:03:13 LOG6[946:3078241136]: SSL_shutdown successfully sent close_notify 
2010.10.15 10:03:13 LOG6[946:3078241136]: s_poll_wait timeout: connection close 
2010.10.15 10:03:13 LOG5[946:3078241136]: Connection closed: 2895 bytes sent to SSL, 2469539 bytes sent to socket 
2010.10.15 10:03:13 LOG7[946:3078241136]: Service https finished (0 left) 
2010.10.15 10:03:13 LOG7[946:3078133552]: Cleaning up the signal pipe 
2010.10.15 10:03:13 LOG6[946:3078133552]: Child process 1179 finished with code 0 
2010.10.15 10:03:13 LOG7[946:3078133552]: Signal pipe is empty 

*** MOST OF THE TIME - AN UNSUCCESSFUL TRANSFER *** 

2010.10.15 10:05:01 LOG7[946:3078133552]: Service https accepted FD=0 from 24.171.161.99:1985 
2010.10.15 10:05:01 LOG7[946:3077921648]: Service https started 
2010.10.15 10:05:01 LOG7[946:3077921648]: FD=0 in non-blocking mode 
2010.10.15 10:05:01 LOG5[946:3077921648]: Service https accepted connection from 24.171.161.99:1985 
2010.10.15 10:05:01 LOG7[946:3077921648]: SSL state (accept): before/ accept initialization 
2010.10.15 10:05:01 LOG7[946:3077921648]: SSL state (accept): SSLv3 read client hello A 
2010.10.15 10:05:01 LOG7[946:3077921648]: SSL state (accept): SSLv3 write server hello A 
2010.10.15 10:05:01 LOG7[946:3077921648]: SSL state (accept): SSLv3 write change cipher spec A 
2010.10.15 10:05:01 LOG7[946:3077921648]: SSL state (accept): SSLv3 write finished A 
2010.10.15 10:05:01 LOG7[946:3077921648]: SSL state (accept): SSLv3 flush data 
2010.10.15 10:05:01 LOG7[946:3077921648]: SSL state (accept): SSLv3 read finished A 
2010.10.15 10:05:01 LOG7[946:3077921648]:    9 items in the session cache 
2010.10.15 10:05:01 LOG7[946:3077921648]:    0 client connects (SSL_connect()) 
2010.10.15 10:05:01 LOG7[946:3077921648]:    0 client connects that finished 
2010.10.15 10:05:01 LOG7[946:3077921648]:    0 client renegotiations requested 
2010.10.15 10:05:01 LOG7[946:3077921648]:   44 server connects (SSL_accept()) 
2010.10.15 10:05:01 LOG7[946:3077921648]:   44 server connects that finished 
2010.10.15 10:05:01 LOG7[946:3077921648]:    0 server renegotiations requested 
2010.10.15 10:05:01 LOG7[946:3077921648]:   35 session cache hits 
2010.10.15 10:05:01 LOG7[946:3077921648]:    0 external session cache hits 
2010.10.15 10:05:01 LOG7[946:3077921648]:    0 session cache misses 
2010.10.15 10:05:01 LOG7[946:3077921648]:    0 session cache timeouts 
2010.10.15 10:05:01 LOG6[946:3077921648]: SSL accepted: previous session reused 
2010.10.15 10:05:01 LOG6[946:3077921648]: Local mode child started (PID=1213) 
2010.10.15 10:05:01 LOG7[946:3077921648]: Remote FD=13 initialized 
2010.10.15 10:05:04 LOG7[946:3077921648]: Socket closed on read 
2010.10.15 10:05:04 LOG7[946:3077921648]: SSL write shutdown 
2010.10.15 10:05:04 LOG7[946:3077921648]: SSL alert (write): warning: close notify 
2010.10.15 10:05:04 LOG6[946:3077921648]: SSL_shutdown successfully sent close_notify 
2010.10.15 10:05:04 LOG6[946:3077921648]: s_poll_wait timeout: connection close 
2010.10.15 10:05:04 LOG5[946:3077921648]: Connection closed: 2895 bytes sent to SSL, 66703 bytes sent to socket 
2010.10.15 10:05:04 LOG7[946:3077921648]: Service https finished (0 left) 
2010.10.15 10:05:04 LOG7[946:3078133552]: Cleaning up the signal pipe 
2010.10.15 10:05:04 LOG6[946:3078133552]: Child process 1213 finished with code 0 
2010.10.15 10:05:04 LOG7[946:3078133552]: Signal pipe is empty 

*** 

All test  cases are the same upload of the same image file. In all tests the number of bytes sent to socket matches what the exec program is receiving in its pipe.

My feeling is that there is a connection issue between the browser and Stunnel. The successful upload of the test occurs sometimes with all browsers and appears to always work with Firefox for Windows. It has a 90% failure rate on Safari for Windows, Safari for Mac, Opera for Windows, Opera for Mac, etc.


In all cases of testing, the number of bytes "sent to socket" is received by my exec program and consists of a truncated message from the browser. It appears that the data is simply being truncated somewhere in the Stunnel process.


Any help is always appreciated!  If there are more tests to be run to track down the problem, please advise and I will run them.

Regards,

Bill

Bill Crowell, President
Pavuk Technologies, LLC
PO Box 33097
Charlotte, NC 28233-3097
Office   +1 704.248.0024 
Mobile +1 704.607.6077
Skype  pavuk.com










-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://www.stunnel.org/pipermail/stunnel-users/attachments/20101015/27fc3f65/attachment.html>

• Previous message (by thread): [stunnel-users] stunnel daemon mode
• Next message (by thread): [stunnel-users] Stunnel dropping data on binary uploads from most browsers.
• Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]