HowtoForge Forums | HowtoForge - Linux Howtos and Tutorials

HowtoForge Forums | HowtoForge - Linux Howtos and Tutorials (http://www.howtoforge.com/forums/index.php)
-   Server Operation (http://www.howtoforge.com/forums/forumdisplay.php?f=5)
-   -   haproxy with stunnel problem (http://www.howtoforge.com/forums/showthread.php?t=55241)

abubin 5th December 2011 11:14

haproxy with stunnel problem
 
We have been using haproxy for quite a few years already for loadbalancing work.

Lately, we need to add https support into our haproxy system. As haproxy does not support https with headers, we need use stunnel for this as suggested in haproxy site.

However, after setting up stunnel for haproxy, 1 week later, we found our server seems to be having massive overloading problem. We are not sure if this is due to additional connections overloading or because of stunnel.

However, I do see a lot of chatter coming from stunnel logs. Below is partial of the logs:
Code:

2011.12.05 17:05:52 LOG5[6644:3080788880]: Service https connected remote server from 127.0.0.1:12829
2011.12.05 17:05:52 LOG5[6644:3082963856]: Service https accepted connection from 112.201.172.38:51234
2011.12.05 17:05:52 LOG5[6644:3074214800]: Service https accepted connection from 112.201.172.38:51235
2011.12.05 17:05:52 LOG5[6644:3080788880]: Connection closed: 471 bytes sent to SSL, 487 bytes sent to socket
2011.12.05 17:05:52 LOG3[6644:3080858512]: SSL_accept: Peer suddenly disconnected
2011.12.05 17:05:52 LOG5[6644:3080858512]: Connection reset: 0 bytes sent to SSL, 0 bytes sent to socket
2011.12.05 17:05:52 LOG5[6644:3082963856]: connect_blocking: connected 0.0.0.0:81
2011.12.05 17:05:52 LOG5[6644:3082963856]: Service https connected remote server from 127.0.0.1:13221
2011.12.05 17:05:52 LOG5[6644:3074214800]: connect_blocking: connected 0.0.0.0:81
2011.12.05 17:05:52 LOG5[6644:3074214800]: Service https connected remote server from 127.0.0.1:13224
2011.12.05 17:05:52 LOG5[6644:3079318416]: Error detected on SSL (read) file descriptor: Connection reset by peer (104)
2011.12.05 17:05:52 LOG5[6644:3079318416]: Connection reset: 471 bytes sent to SSL, 488 bytes sent to socket
2011.12.05 17:05:53 LOG5[6644:3078970256]: Connection closed: 927 bytes sent to SSL, 497 bytes sent to socket
2011.12.05 17:05:53 LOG5[6644:3074214800]: Connection closed: 471 bytes sent to SSL, 492 bytes sent to socket
2011.12.05 17:05:53 LOG5[6644:3082963856]: Connection closed: 471 bytes sent to SSL, 487 bytes sent to socket
2011.12.05 17:05:53 LOG5[6644:3082963856]: Service https accepted connection from 112.202.184.50:50226
2011.12.05 17:05:53 LOG5[6644:3074214800]: Service https accepted connection from 112.202.184.50:50227
2011.12.05 17:05:53 LOG5[6644:3078970256]: Service https accepted connection from 112.202.184.50:50228
2011.12.05 17:05:53 LOG5[6644:3074075536]: Error detected on SSL (read) file descriptor: Connection reset by peer (104)
2011.12.05 17:05:53 LOG5[6644:3074075536]: Connection reset: 471 bytes sent to SSL, 493 bytes sent to socket
2011.12.05 17:05:53 LOG5[6644:3074075536]: Service https accepted connection from 118.137.180.101:50363
2011.12.05 17:05:53 LOG5[6644:3079318416]: Service https accepted connection from 182.52.155.183:15604
2011.12.05 17:05:53 LOG5[6644:3080858512]: Service https accepted connection from 182.52.155.183:15605
2011.12.05 17:05:53 LOG5[6644:3082963856]: connect_blocking: connected 0.0.0.0:81
2011.12.05 17:05:53 LOG5[6644:3082963856]: Service https connected remote server from 127.0.0.1:14159
2011.12.05 17:05:53 LOG5[6644:3078970256]: connect_blocking: connected 0.0.0.0:81
2011.12.05 17:05:53 LOG5[6644:3078970256]: Service https connected remote server from 127.0.0.1:14161
2011.12.05 17:05:53 LOG5[6644:3074214800]: connect_blocking: connected 0.0.0.0:81
2011.12.05 17:05:53 LOG5[6644:3074214800]: Service https connected remote server from 127.0.0.1:14160
2011.12.05 17:05:53 LOG5[6644:3081694096]: Connection closed: 927 bytes sent to SSL, 435 bytes sent to socket
2011.12.05 17:05:53 LOG5[6644:3081694096]: Service https accepted connection from 180.190.168.178:50767
2011.12.05 17:05:54 LOG5[6644:3078970256]: Connection closed: 471 bytes sent to SSL, 517 bytes sent to socket
2011.12.05 17:05:54 LOG5[6644:3078970256]: Service https accepted connection from 115.165.160.66:62098
2011.12.05 17:05:54 LOG5[6644:3081694096]: connect_blocking: connected 0.0.0.0:81
2011.12.05 17:05:54 LOG5[6644:3081694096]: Service https connected remote server from 127.0.0.1:14483
2011.12.05 17:05:54 LOG5[6644:3074214800]: Connection closed: 471 bytes sent to SSL, 512 bytes sent to socket
2011.12.05 17:05:54 LOG5[6644:3074214800]: Service https accepted connection from 122.3.31.46:39483
2011.12.05 17:05:54 LOG5[6644:3080788880]: Service https accepted connection from 122.3.31.46:39484
2011.12.05 17:05:54 LOG5[6644:3081485200]: Service https accepted connection from 122.3.31.46:39485
2011.12.05 17:05:54 LOG5[6644:3079318416]: connect_blocking: connected 0.0.0.0:81
2011.12.05 17:05:54 LOG5[6644:3079318416]: Service https connected remote server from 127.0.0.1:14565
2011.12.05 17:05:54 LOG5[6644:3080858512]: connect_blocking: connected 0.0.0.0:81
2011.12.05 17:05:54 LOG5[6644:3080858512]: Service https connected remote server from 127.0.0.1:14637
2011.12.05 17:05:54 LOG5[6644:3082963856]: Connection closed: 471 bytes sent to SSL, 512 bytes sent to socket
2011.12.05 17:05:54 LOG5[6644:3082963856]: Service https accepted connection from 222.127.252.203:64831
2011.12.05 17:05:54 LOG5[6644:3074075536]: connect_blocking: connected 0.0.0.0:81
2011.12.05 17:05:54 LOG5[6644:3074075536]: Service https connected remote server from 127.0.0.1:14727
2011.12.05 17:05:54 LOG5[6644:3078970256]: connect_blocking: connected 0.0.0.0:81
2011.12.05 17:05:54 LOG5[6644:3078970256]: Service https connected remote server from 127.0.0.1:14750
2011.12.05 17:05:54 LOG5[6644:3081694096]: Connection closed: 927 bytes sent to SSL, 398 bytes sent to socket
2011.12.05 17:05:54 LOG5[6644:3074214800]: connect_blocking: connected 0.0.0.0:81
2011.12.05 17:05:54 LOG5[6644:3074214800]: Service https connected remote server from 127.0.0.1:14795
2011.12.05 17:05:54 LOG5[6644:3080788880]: connect_blocking: connected 0.0.0.0:81
2011.12.05 17:05:54 LOG5[6644:3080788880]: Service https connected remote server from 127.0.0.1:14806
2011.12.05 17:05:54 LOG5[6644:3081485200]: connect_blocking: connected 0.0.0.0:81
2011.12.05 17:05:54 LOG5[6644:3081485200]: Service https connected remote server from 127.0.0.1:14809
2011.12.05 17:05:54 LOG5[6644:3081694096]: Service https accepted connection from 112.205.167.15:63151
2011.12.05 17:05:54 LOG5[6644:3079666576]: Service https accepted connection from 112.205.167.15:63389
2011.12.05 17:05:54 LOG5[6644:3081206672]: Service https accepted connection from 124.105.33.133:52801
2011.12.05 17:05:54 LOG5[6644:3081415568]: Service https accepted connection from 175.139.201.97:56748
2011.12.05 17:05:54 LOG5[6644:3074214800]: Connection closed: 471 bytes sent to SSL, 450 bytes sent to socket
2011.12.05 17:05:54 LOG5[6644:3081415568]: connect_blocking: connected 0.0.0.0:81
2011.12.05 17:05:54 LOG5[6644:3081415568]: Service https connected remote server from 127.0.0.1:14974
2011.12.05 17:05:54 LOG5[6644:3081485200]: Connection closed: 471 bytes sent to SSL, 455 bytes sent to socket
2011.12.05 17:05:54 LOG5[6644:3081415568]: Connection closed: 795 bytes sent to SSL, 1552 bytes sent to socket
2011.12.05 17:05:54 LOG5[6644:3080788880]: Connection closed: 471 bytes sent to SSL, 450 bytes sent to socket
2011.12.05 17:05:54 LOG5[6644:3081694096]: connect_blocking: connected 0.0.0.0:81
2011.12.05 17:05:54 LOG5[6644:3081694096]: Service https connected remote server from 127.0.0.1:15184
2011.12.05 17:05:54 LOG5[6644:3078970256]: Connection closed: 388 bytes sent to SSL, 702 bytes sent to socket
2011.12.05 17:05:54 LOG5[6644:3079666576]: connect_blocking: connected 0.0.0.0:81
2011.12.05 17:05:54 LOG5[6644:3079666576]: Service https connected remote server from 127.0.0.1:15354
2011.12.05 17:05:55 LOG5[6644:3079318416]: Connection closed: 608 bytes sent to SSL, 1282 bytes sent to socket
2011.12.05 17:05:55 LOG5[6644:3080858512]: Connection closed: 605 bytes sent to SSL, 1282 bytes sent to socket
2011.12.05 17:05:55 LOG5[6644:3081694096]: Connection closed: 471 bytes sent to SSL, 604 bytes sent to socket
2011.12.05 17:05:55 LOG5[6644:3081694096]: Service https accepted connection from 119.92.130.94:30655
2011.12.05 17:05:55 LOG5[6644:3079666576]: Connection closed: 471 bytes sent to SSL, 604 bytes sent to socket
2011.12.05 17:05:55 LOG5[6644:3079666576]: Service https accepted connection from 182.52.155.183:15622
2011.12.05 17:05:55 LOG5[6644:3080858512]: Service https accepted connection from 182.52.155.183:15624
2011.12.05 17:05:55 LOG5[6644:3079318416]: Service https accepted connection from 112.205.167.15:64751
2011.12.05 17:05:55 LOG5[6644:3078970256]: Service https accepted connection from 175.139.201.97:56752
2011.12.05 17:05:55 LOG5[6644:3078970256]: connect_blocking: connected 0.0.0.0:81
2011.12.05 17:05:55 LOG5[6644:3078970256]: Service https connected remote server from 127.0.0.1:16124
2011.12.05 17:05:55 LOG5[6644:3078970256]: Connection closed: 795 bytes sent to SSL, 1552 bytes sent to socket
2011.12.05 17:05:55 LOG5[6644:3078970256]: Service https accepted connection from 182.52.155.183:15627
2011.12.05 17:05:55 LOG5[6644:3079666576]: connect_blocking: connected 0.0.0.0:81
2011.12.05 17:05:55 LOG5[6644:3079666576]: Service https connected remote server from 127.0.0.1:16292
2011.12.05 17:05:55 LOG5[6644:3080858512]: connect_blocking: connected 0.0.0.0:81
2011.12.05 17:05:55 LOG5[6644:3079318416]: connect_blocking: connected 0.0.0.0:81
2011.12.05 17:05:55 LOG5[6644:3079318416]: Service https connected remote server from 127.0.0.1:16369
2011.12.05 17:05:55 LOG5[6644:3080858512]: Service https connected remote server from 127.0.0.1:16368
2011.12.05 17:05:56 LOG3[6644:3081206672]: SSL_accept: Peer suddenly disconnected
2011.12.05 17:05:56 LOG5[6644:3081206672]: Connection reset: 0 bytes sent to SSL, 0 bytes sent to socket
2011.12.05 17:05:56 LOG5[6644:3081206672]: Service https accepted connection from 222.127.47.172:12444
2011.12.05 17:05:56 LOG5[6644:3079318416]: Connection closed: 471 bytes sent to SSL, 609 bytes sent to socket
2011.12.05 17:05:56 LOG5[6644:3079318416]: Service https accepted connection from 222.127.47.172:58786
2011.12.05 17:05:56 LOG5[6644:3080788880]: Service https accepted connection from 180.190.168.178:50775
2011.12.05 17:05:56 LOG5[6644:3081415568]: Service https accepted connection from 180.190.168.178:50776
2011.12.05 17:05:56 LOG5[6644:3081485200]: Service https accepted connection from 180.190.168.178:50777
2011.12.05 17:05:56 LOG5[6644:3079666576]: Connection closed: 471 bytes sent to SSL, 1336 bytes sent to socket
2011.12.05 17:05:56 LOG5[6644:3083660176]: connect_blocking: connected 0.0.0.0:81
2011.12.05 17:05:56 LOG5[6644:3083660176]: Service https connected remote server from 127.0.0.1:17039
2011.12.05 17:05:56 LOG5[6644:3081206672]: connect_blocking: connected 0.0.0.0:81
2011.12.05 17:05:56 LOG5[6644:3081206672]: Service https connected remote server from 127.0.0.1:17137
2011.12.05 17:05:56 LOG5[6644:3080788880]: connect_blocking: connected 0.0.0.0:81
2011.12.05 17:05:56 LOG5[6644:3080788880]: Service https connected remote server from 127.0.0.1:17138
2011.12.05 17:05:56 LOG5[6644:3081415568]: connect_blocking: connected 0.0.0.0:81
2011.12.05 17:05:56 LOG5[6644:3081415568]: Service https connected remote server from 127.0.0.1:17240
2011.12.05 17:05:56 LOG5[6644:3080858512]: Connection closed: 471 bytes sent to SSL, 1336 bytes sent to socket
2011.12.05 17:05:56 LOG5[6644:3081485200]: connect_blocking: connected 0.0.0.0:81
2011.12.05 17:05:56 LOG5[6644:3081485200]: Service https connected remote server from 127.0.0.1:17247
2011.12.05 17:05:56 LOG5[6644:3080788880]: Connection closed: 471 bytes sent to SSL, 447 bytes sent to socket
2011.12.05 17:05:56 LOG5[6644:3081415568]: Connection closed: 471 bytes sent to SSL, 447 bytes sent to socket
2011.12.05 17:05:56 LOG5[6644:3081415568]: Service https accepted connection from 182.52.155.183:15611
2011.12.05 17:05:56 LOG5[6644:3080788880]: Service https accepted connection from 182.52.155.183:15609
2011.12.05 17:05:56 LOG5[6644:3080858512]: Service https accepted connection from 121.96.72.246:47481
2011.12.05 17:05:56 LOG5[6644:3081485200]: Connection closed: 471 bytes sent to SSL, 452 bytes sent to socket
2011.12.05 17:05:56 LOG5[6644:3081206672]: Connection closed: 927 bytes sent to SSL, 503 bytes sent to socket
2011.12.05 17:05:56 LOG5[6644:3078970256]: connect_blocking: connected 0.0.0.0:81
2011.12.05 17:05:56 LOG5[6644:3078970256]: Service https connected remote server from 127.0.0.1:17737
2011.12.05 17:05:57 LOG3[6644:3079527312]: SSL_accept: Peer suddenly disconnected
2011.12.05 17:05:57 LOG5[6644:3079527312]: Connection reset: 0 bytes sent to SSL, 0 bytes sent to socket
2011.12.05 17:05:57 LOG5[6644:3083660176]: Connection closed: 927 bytes sent to SSL, 411 bytes sent to socket
2011.12.05 17:05:57 LOG5[6644:3083660176]: Service https accepted connection from 125.60.227.195:14828
2011.12.05 17:05:57 LOG5[6644:3080858512]: connect_blocking: connected 0.0.0.0:81
2011.12.05 17:05:57 LOG5[6644:3080858512]: Service https connected remote server from 127.0.0.1:18370
2011.12.05 17:05:57 LOG5[6644:3081694096]: connect_blocking: connected 0.0.0.0:81
2011.12.05 17:05:57 LOG5[6644:3081694096]: Service https connected remote server from 127.0.0.1:18515
2011.12.05 17:05:57 LOG5[6644:3079527312]: Service https accepted connection from 119.92.130.94:26843
2011.12.05 17:05:57 LOG5[6644:3081206672]: Service https accepted connection from 119.92.130.94:55673
2011.12.05 17:05:57 LOG5[6644:3083660176]: connect_blocking: connected 0.0.0.0:81
2011.12.05 17:05:57 LOG5[6644:3083660176]: Service https connected remote server from 127.0.0.1:18737
2011.12.05 17:05:57 LOG5[6644:3081415568]: connect_blocking: connected 0.0.0.0:81
2011.12.05 17:05:57 LOG5[6644:3081415568]: Service https connected remote server from 127.0.0.1:18749
2011.12.05 17:05:57 LOG5[6644:3080788880]: connect_blocking: connected 0.0.0.0:81
2011.12.05 17:05:57 LOG5[6644:3080788880]: Service https connected remote server from 127.0.0.1:18752

Here is our config for stunnel.conf:
socket=l:TCP_NODELAY=1
socket=r:TCP_NODELAY=1

[https]
cert=/etc/stunnel/avn.innity.com.crt
key=/etc/stunnel/avn.innity.com.key
accept=0.0.0.0:443
connect=0.0.0.0:81
xforwardedfor=yes

And below is PART of our haproxy config for https:
listen web-https *:81
contimeout 30000
mode http
balance roundrobin
option httpclose
option forwardfor except 127.0.0.1
option httpchk HEAD /robots.txt HTTP/1.0
reqadd X-Forwarded-Proto:\ https
server 1.2.3.1 1.2.3.1:80 minconn 400 maxconn 600 weight 2 check
server 1.2.3.2 1.2.3.2:80 minconn 400 maxconn 600 weight 2 check
server 1.2.3.3 1.2.3.3:80 minconn 200 maxconn 400 weight 1 check backup


Anyone can help to see what's the problem? I can't find any solutions based on the logs from stunnel. Cause https seems to be working fine through the haproxy server.

The-Bat 30th December 2011 15:51

Even I have got the same issue. What does these lines mean ?

2011.12.05 17:05:52 LOG5[6644:3079318416]: Error detected on SSL (read) file descriptor: Connection reset by peer (104)
2011.12.05 17:05:52 LOG5[6644:3079318416]: Connection reset: 471 bytes sent to SSL, 488 bytes sent to socket

Any idea ?

mansonthomas 31st March 2012 01:30

Hi,


i've the same setup : HAProxy + stunnel and the same error...

did you find what's wrong ?

on my installation, I can get https working for some time and then I get "connexion to the server has been reset while loading it" (translated from french)

and I can't have 2 stunnels running at the same time, it ignores one saying it's already running while it's not...

any help would be very apprecieated since I'm stuck at this for a while and my client is yelling;)

Thomas.

wtarreau 6th April 2012 08:34

I think that your problem comes from the lack of timeouts in both your stunnel config and your haproxy config. From time to time, some clients disconnect from the net in a dirty fashion, resulting in a lot of unterminated connections pending on your server. At one point, all stunnel's connections are used and you can't connect anymore. It is *very* important to apply timeouts on *every* component in a web infrastructure, otherwise it is 100% sure that it will fail.

Also you can improve your performance and decrease this issue by replacing "option httpclose" with "option http-server-close", which will maintain keep-alive to the clients. It will also slightly hide the
effects of your lack of timeouts.

mansonthomas 6th April 2012 11:48

Hi Willy,

thanks for your reply.

So I should add

"option http-server-close"
after the listen instruction ? (for both http & https ?)
(I didn't have option http-close in my setup... )

I've seen while googling this option that one can add "mode http".
I don't have it in my current setup, could this be the root of the issue ?
(well after reading this : http://code.google.com/p/haproxy-docs/wiki/mode I don't think so)

And about Stunnel, I sould put something else that TIMEOUTclose = 0?
like 60 seconds?

==> your post + some googling is really rewarding ;)

Stunnel :
Code:

debug = 7
output = /var/log/stunnel4/extranet.service.com_stunnel.log
setuid = stunnel4
setgid = stunnel4
pid = /var/run/stunnel4/extranet.service.com.pid
socket = l:TCP_NODELAY=1
socket = r:TCP_NODELAY=1


[extranet.service.com]
key          = /etc/stunnel/sites/extranet.service.com/extranet.service.com.key
cert          = /etc/stunnel/sites/extranet.service.com/extranet.service.com.crt
accept        = 8.90.17.4:443
connect      = 127.0.0.1:82

sslVersion = SSLv3
TIMEOUTclose  = 0


HAProxy:
Code:

# this config needs haproxy-1.1.28 or haproxy-1.2.1

global
  log      127.0.0.1  local0
  log      127.0.0.1  local1 notice
  #log loghost  local0 info
# default value of maxcon overrided because of the Error 502 issue due to prestashop large header
# maxconn  4096
  #chroot /usr/share/haproxy
  user    haproxy
  group    haproxy
  daemon
#Probleme d'erreur 502 avec prestashop (valeur par défaut : 16384)
  tune.bufsize 65536
#maxcon(default = 4096) *4 : as we increase the bufsize*2 (according to the documentation maxcon should be increased by the same multiplier we used for bufsize (compared to its initiale value)
  maxconn  16384
  #debug
  #quiet

defaults
  log        global
  mode        http
  option      httplog
  option      dontlognull
  retries    3
  option      redispatch
  maxconn    2000
  contimeout  5000
  clitimeout  50000
  srvtimeout  50000

listen    dedibox_cluster1 0.0.0.0:80
  stats  enable
  stats  auth user:pwd  cookie  SERVERID insert indirect nocache
  balance roundrobin
  server  s1.monsite.com 8.91.02.7:80 cookie app1inst1 check inter 2000 rise 2 fall 5
  server  s2.monsite.com 8.91.8.2:80  cookie app1inst2 check inter 2000 rise 2 fall 5

#instance pour le https
listen    dedibox_cluster1_https 127.0.0.1:82
  stats  enable
  stats  auth user:pwd
  cookie  SERVERID insert indirect nocache
  balance roundrobin
  server  s1.monsite.com 8.91.02.7:80 cookie app1inst1 check inter 2000 rise 2 fall 5
  server  s2.monsite.com 8.91.8.2:80  cookie app1inst2 check inter 2000 rise 2 fall 5


  #errorloc 502 http://192.168.114.58/error502.html
  #errorfile  503 /etc/haproxy/errors/503.http
  errorfile 400 /etc/haproxy/errors/400.http
  errorfile 403 /etc/haproxy/errors/403.http
  errorfile 408 /etc/haproxy/errors/408.http
  errorfile 500 /etc/haproxy/errors/500.http
  errorfile 502 /etc/haproxy/errors/502.http

Thanks for your help !
I didn't get much replies on stunnel mailing list and was a bit desperate ;)
Thomas.

mansonthomas 6th April 2012 12:05

(humm.... i've mode http in my default section ;))

mansonthomas 10th April 2012 16:08

Find my issue's root
 
Hi Willy,

I found the root of the issue.

The version of stunnel shipped with Ubuntu 11.10 has the following defect :

Quote:

Version 4.38, 2011.06.28, urgency: MEDIUM:

New features
* Server-side SNI implemented (RFC 3546 section 3.1) with a new service-level option "nsi".
* "socket" option also accepts "yes" and "no" for flags.
* Nagle's algorithm is now disabled by default for improved interactivity.

Bugfixes
* A compilation fix was added for OpenSSL version < 1.0.0.
* Signal pipe set to non-blocking mode. This bug caused hangs of stunnel features based on signals, e.g. local mode, FORK threading, or configuration file reload on Unix. Win32 platform was not affected.
I've compiled the last version 4.53 and the issue has not been reproduced.

Thanks for your help!

Thomas.


All times are GMT +2. The time now is 20:10.

Powered by vBulletin® Version 3.8.7
Copyright ©2000 - 2014, vBulletin Solutions, Inc.