[stunnel-users] stunnel 4.14 died silently under traffic stress test
Zhuang Yuyao
mlistz at gmail.com
Fri Mar 10 03:14:26 CET 2006
Thanks Michal for your quick reply.
Here are some additional informations:
kernel: 2.6.15.4
libc: uClibc (http://uclibc.org) 0.9.28 (but this problem can also be
reproduced on a powerpc 405ep board of 64M RAM with glibc 2.3.6-nptl)
The gateway machine running stunnel DO NOT have swap! so the available
memory is limited to its physical memory = 64M.
I've searched the web for some hints, I found something here:
http://www.win.tue.nl/~aeb/linux/lk/lk-9.html, it looks like the kernel
killed stunnel for out of memory (OOM), but though i set:
echo 2 > /proc/sys/vm/overcommit_memory
echo 100 > /proc/sys/vm/overcommit_ratio
run demo program 2 (you can find the source code here
http://www.win.tue.nl/~aeb/linux/lk/lk-9.html)
#./demo2
got 1 MiB
got 2 MiB
got 3 MiB
got 4 MiB
got 5 MiB
got 6 MiB
got 7 MiB
got 8 MiB
got 9 MiB
got 10 MiB
got 11 MiB
got 12 MiB
got 13 MiB
got 14 MiB
got 15 MiB
got 16 MiB
got 17 MiB
got 18 MiB
got 19 MiB
got 20 MiB
got 21 MiB
got 22 MiB
got 23 MiB
got 24 MiB
got 25 MiB
got 26 MiB
got 27 MiB
got 28 MiB
got 29 MiB
got 30 MiB
got 31 MiB
got 32 MiB
got 33 MiB
got 34 MiB
got 35 MiB
got 36 MiB
got 37 MiB
got 38 MiB
got 39 MiB
got 40 MiB
got 41 MiB
got 42 MiB
got 43 MiB
got 44 MiB
malloc failure after 44 MiB
but the problem is still there.
Running strace (http://www.liacs.nl/~wichert/strace/) with
foreground=yes, the last output shows:
.......
poll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}], 2, -1) = -1 EINTR
(Interrupted system call)
+++ killed by SIGKILL +++
Michal Trojnara wrote:
> Hi,
>
> It works fine for me (at least with the latest stunnel):
>
>
> mtrojnar at moses:~$ /usr/sbin/ab2 -n 200 -c 100
> https://localhost:443/test.bin
> This is ApacheBench, Version 2.0.41-dev <$Revision: 1.141 $> apache-2.0
> Copyright (c) 1996 Adam Twiss, Zeus Technology Ltd,
> http://www.zeustech.net/
> Copyright (c) 1998-2002 The Apache Software Foundation,
> http://www.apache.org/
>
> Benchmarking localhost (be patient)
> Completed 100 requests
> Finished 200 requests
>
>
> Server Software: Apache/1.3.33
> Server Hostname: localhost
> Server Port: 443
>
> Document Path: /test.bin
> Document Length: 102400 bytes
>
> Concurrency Level: 100
> Time taken for tests: 171.947630 seconds
> Complete requests: 200
> Failed requests: 0
> Write errors: 0
> Total transferred: 20555000 bytes
> HTML transferred: 20480000 bytes
> Requests per second: 1.16 [#/sec] (mean)
> Time per request: 85973.816 [ms] (mean)
> Time per request: 859.738 [ms] (mean, across all concurrent requests)
> Transfer rate: 116.74 [Kbytes/sec] received
>
> Connection Times (ms)
> min mean[+/-sd] median max
> Connect: 9 13 9.9 12 105
> Processing: 16323 85244 30229.0 85741 154677
> Waiting: 491 12441 10179.3 6444 25462
> Total: 16335 85258 30228.4 85752 154687
>
> Percentage of the requests served within a certain time (ms)
> 50% 85752
> 66% 97393
> 75% 105041
> 80% 108860
> 90% 130262
> 95% 137270
> 98% 152093
> 99% 154180
> 100% 154687 (longest request)
>
>
> moses:/home/mtrojnar# /usr/local/sbin/stunnel
> 2006.03.09 21:39:59 LOG5[14429:3084914816]: stunnel 4.15 on
> i686-pc-linux-gnu with OpenSSL 0.9.8a 11 Oct 2005
> 2006.03.09 21:39:59 LOG5[14429:3084914816]: Threading:PTHREAD
> Sockets:POLL,IPv4 SSL:ENGINE Auth:LIBWRAP
> 2006.03.09 21:39:59 LOG5[14429:3084914816]: 500 clients allowed
> 2006.03.09 21:40:20 LOG5[14429:3086560176]: https connected from
> 127.0.0.1:49868
> 2006.03.09 21:40:20 LOG5[14429:3084913584]: https connected from
> 127.0.0.1:49869
> 2006.03.09 21:40:20 LOG5[14429:3084848048]: https connected from
> 127.0.0.1:49871
> 2006.03.09 21:40:20 LOG5[14429:3084782512]: https connected from
> 127.0.0.1:49873
> ...
> 2006.03.09 21:51:28 LOG5[14429:3083537328]: Connection closed: 102775
> bytes sent to SSL, 92 bytes sent to socket
> 2006.03.09 21:51:28 LOG5[14429:3083930544]: Connection closed: 102775
> bytes sent to SSL, 92 bytes sent to socket
> 2006.03.09 21:51:28 LOG5[14429:3080784816]: Connection closed: 102775
> bytes sent to SSL, 92 bytes sent to socket
> 2006.03.09 21:51:28 LOG5[14429:3081636784]: Connection closed: 102775
> bytes sent to SSL, 92 bytes sent to socket
>
>
> Maybe you could try running stunnel with "foreground = yes" using gdb?
> What is the version of your kernel and glibc?
>
>
> Best regards,
> Mike
>
> On 2006-03-09, at 08:29, Zhuang Yuyao wrote:
>
>> Hi,
>>
>> While doing apache benchmark test, stunnel 4.14 died silently.
>>
>> Network topo:
>> client(192.168.20.81 debian running ab2) ---(https)--->
>> gateway(192.168.20.1 running stunnel in server mode) ---(http)---> web
>> server(192.168.10.254)
>>
>> Gateway hardware:
>> 80386 compatible cpu (VIA C3 400Mhz);
>> RAM: 64M
>>
>> stunnel.conf:
>> ###############################
>> .....
>> compression = zlib
>> client = no
>> ciphers = DES-CBC3-SHA:DES-CBC3-MD5
>> verify = 1
>> [test]
>> accept = 443
>> connect = 192.168.10.254:80
>> TIMEOUTclose = 0
>> ###############################
>>
>> Web Server hardware:
>> Dell 2850 with 2G RAM.
>> test_100k.html is a html file whose size is 100k bytes.
>> test_4k.html is a html file whose size is 4k bytes.
>>
>> In client, I am using ab2 as the stress test tool:
>> #ab2 -n 200 -c 100 https://192.168.20.1:443/test_4k.html (means 200
>> request and 100 concurrency)
>> successfully finished.
>>
>> #ab2 -n 200 -c 100 https://192.168.20.1:443/test_100k.html (means 200
>> request and 100 concurrency)
>> stunnel died after a few seconds, running log shows:
>> 2006.03.09 15:20:39 LOG5[6962:1024]: stunnel 4.14 on i386-pc-linux-gnu
>> PTHREAD+POLL+IPv4 with OpenSSL 0.9.7i 14 Oct 2005
>> 2006.03.09 15:20:39 LOG5[6962:1024]: 500 clients allowed
>> 2006.03.09 15:20:53 LOG5[6964:1026]: test connected from
>> 192.168.20.81:50186
>> 2006.03.09 15:20:53 LOG5[6965:2051]: test connected from
>> 192.168.20.81:50187
>> 2006.03.09 15:20:53 LOG5[6966:3076]: test connected from
>> 192.168.20.81:50188
>> 2006.03.09 15:20:53 LOG5[6967:4101]: test connected from
>> 192.168.20.81:50189
>> 2006.03.09 15:20:53 LOG5[6968:5126]: test connected from
>> 192.168.20.81:50190
>> 2006.03.09 15:20:54 LOG5[6969:6151]: test connected from
>> 192.168.20.81:50191
>> 2006.03.09 15:20:54 LOG5[6970:7176]: test connected from
>> 192.168.20.81:50192
>> 2006.03.09 15:20:54 LOG5[6971:8201]: test connected from
>> 192.168.20.81:50193
>> 2006.03.09 15:20:54 LOG5[6972:9226]: test connected from
>> 192.168.20.81:50194
>> 2006.03.09 15:20:54 LOG5[6973:10251]: test connected from
>> 192.168.20.81:50195
>> 2006.03.09 15:20:54 LOG5[6974:11276]: test connected from
>> 192.168.20.81:50196
>> 2006.03.09 15:20:54 LOG5[6975:12301]: test connected from
>> 192.168.20.81:50197
>> 2006.03.09 15:20:54 LOG5[6976:13326]: test connected from
>> 192.168.20.81:50198
>> 2006.03.09 15:20:54 LOG5[6977:14351]: test connected from
>> 192.168.20.81:50199
>> 2006.03.09 15:20:54 LOG5[6978:15376]: test connected from
>> 192.168.20.81:50200
>> 2006.03.09 15:20:54 LOG5[6979:16401]: test connected from
>> 192.168.20.81:50201
>> 2006.03.09 15:20:54 LOG5[6980:17426]: test connected from
>> 192.168.20.81:50202
>> 2006.03.09 15:20:54 LOG5[6981:18451]: test connected from
>> 192.168.20.81:50203
>> 2006.03.09 15:20:54 LOG5[6982:19476]: test connected from
>> 192.168.20.81:50204
>> 2006.03.09 15:20:54 LOG5[6983:20501]: test connected from
>> 192.168.20.81:50205
>> 2006.03.09 15:20:54 LOG5[6984:21526]: test connected from
>> 192.168.20.81:50206
>> 2006.03.09 15:20:54 LOG5[6985:22551]: test connected from
>> 192.168.20.81:50207
>> 2006.03.09 15:20:54 LOG5[6986:23576]: test connected from
>> 192.168.20.81:50208
>> 2006.03.09 15:20:54 LOG5[6987:24601]: test connected from
>> 192.168.20.81:50209
>> 2006.03.09 15:20:54 LOG5[6988:25626]: test connected from
>> 192.168.20.81:50210
>> 2006.03.09 15:20:54 LOG5[6989:26651]: test connected from
>> 192.168.20.81:50211
>> 2006.03.09 15:20:54 LOG5[6990:27676]: test connected from
>> 192.168.20.81:50212
>> 2006.03.09 15:20:54 LOG5[6991:28701]: test connected from
>> 192.168.20.81:50213
>> 2006.03.09 15:20:54 LOG5[6992:29726]: test connected from
>> 192.168.20.81:50214
>> 2006.03.09 15:20:54 LOG5[6993:30751]: test connected from
>> 192.168.20.81:50215
>> 2006.03.09 15:20:54 LOG5[6994:31776]: test connected from
>> 192.168.20.81:50216
>> 2006.03.09 15:20:54 LOG5[6995:32801]: test connected from
>> 192.168.20.81:50217
>> 2006.03.09 15:20:54 LOG5[6996:33826]: test connected from
>> 192.168.20.81:50218
>> 2006.03.09 15:20:54 LOG5[6997:34851]: test connected from
>> 192.168.20.81:50219
>> 2006.03.09 15:20:54 LOG5[6998:35876]: test connected from
>> 192.168.20.81:50220
>> 2006.03.09 15:20:54 LOG5[6999:36901]: test connected from
>> 192.168.20.81:50221
>> 2006.03.09 15:20:54 LOG5[7000:37926]: test connected from
>> 192.168.20.81:50222
>> 2006.03.09 15:20:54 LOG5[7001:38951]: test connected from
>> 192.168.20.81:50223
>> 2006.03.09 15:20:54 LOG5[7002:39976]: test connected from
>> 192.168.20.81:50224
>> 2006.03.09 15:20:54 LOG5[7003:41001]: test connected from
>> 192.168.20.81:50225
>> 2006.03.09 15:20:54 LOG5[7004:42026]: test connected from
>> 192.168.20.81:50226
>> 2006.03.09 15:20:55 LOG5[7005:43051]: test connected from
>> 192.168.20.81:50227
>> 2006.03.09 15:20:55 LOG5[7006:44076]: test connected from
>> 192.168.20.81:50228
>> 2006.03.09 15:20:55 LOG5[7007:45101]: test connected from
>> 192.168.20.81:50229
>> 2006.03.09 15:20:55 LOG5[7008:46126]: test connected from
>> 192.168.20.81:50230
>> 2006.03.09 15:20:55 LOG5[7009:47151]: test connected from
>> 192.168.20.81:50231
>> 2006.03.09 15:20:55 LOG5[7010:48176]: test connected from
>> 192.168.20.81:50232
>> 2006.03.09 15:20:55 LOG5[7011:49201]: test connected from
>> 192.168.20.81:50233
>> 2006.03.09 15:20:55 LOG5[7012:50226]: test connected from
>> 192.168.20.81:50234
>> 2006.03.09 15:20:55 LOG5[7013:51251]: test connected from
>> 192.168.20.81:50235
>> 2006.03.09 15:20:55 LOG5[7014:52276]: test connected from
>> 192.168.20.81:50236
>> 2006.03.09 15:20:55 LOG5[7015:53301]: test connected from
>> 192.168.20.81:50237
>> 2006.03.09 15:20:55 LOG5[7016:54326]: test connected from
>> 192.168.20.81:50238
>> 2006.03.09 15:20:55 LOG5[7017:55351]: test connected from
>> 192.168.20.81:50239
>> 2006.03.09 15:20:55 LOG5[7018:56376]: test connected from
>> 192.168.20.81:50240
>> 2006.03.09 15:20:55 LOG5[7019:57401]: test connected from
>> 192.168.20.81:50241
>> 2006.03.09 15:20:55 LOG5[7020:58426]: test connected from
>> 192.168.20.81:50242
>> 2006.03.09 15:20:55 LOG5[7021:59451]: test connected from
>> 192.168.20.81:50243
>> 2006.03.09 15:20:55 LOG5[7022:60476]: test connected from
>> 192.168.20.81:50244
>> 2006.03.09 15:20:55 LOG5[7023:61501]: test connected from
>> 192.168.20.81:50245
>> 2006.03.09 15:20:55 LOG5[7024:62526]: test connected from
>> 192.168.20.81:50246
>> Killed
>>
>> It looks like that is resource on gateway is exhausted under such a
>> traffic, but my question is: why stunnel just died instead of
>> rejecting further connections.
>>
>> Thanks very much.
>>
>> Zhuang Yuyao
>> _______________________________________________
>> stunnel-users mailing list
>> stunnel-users at mirt.net
>> http://stunnel.mirt.net/mailman/listinfo/stunnel-users
>
> _______________________________________________
> stunnel-users mailing list
> stunnel-users at mirt.net
> http://stunnel.mirt.net/mailman/listinfo/stunnel-users
>
More information about the stunnel-users
mailing list