Apache :: SSL Requests Stop working after a while

Apache LoungeWebmasters

About Forum Index Downloads Search Register Log in RSS X

Keep Server Online

If you find the Apache Lounge, the downloads and overall help useful, please express your satisfaction with a donation.

or

A donation makes a contribution towards the costs, the time and effort that's going in this site and building.

Thank You! Steffen

Your donations will help to keep this site alive and well, and continuing building binaries. Apache Lounge is not sponsored.

Forum Index -> Apache

View previous topic :: View next topic

Topic: SSL Requests Stop working after a while

Author

skillsfactory

Joined: 27 Sep 2013
Posts: 11
Location: Italy

Posted: Sun 29 Sep '13 10:57 Post subject: SSL Requests Stop working after a while

I have Apache 2.4.2, OpenSSL/1.0.1c, on Windows Web Server 2008 R2 (64 bits)

After 12 hours of heavier load, the SSL requests stopped working/being answered. However if you requested the same page via http instead of https, it worked fine.
Restarting the Apache server fixes this, for a while. Again after a few hours of traffic, the https requests stopped working again.
I checked the logs, and nothing notable, the mod_ssl entries just...

The site is called only by client developed with Delphi 2007 (CodeGear user-agent). Delphi client use THTTPRIO for sending HTTPS request to SOAP.

Any ideas?

httpd.conf

Code:

AcceptFilter http none
# AcceptFilter https none (try to uncomment, but ssl stop work)
EnableMMAP off
EnableSendfile off

httpd-ssl.conf

Code:

Listen 443
SSLPassPhraseDialog builtin
SSLSessionCache "shmcb:logs/ssl.scache(512000)"
SSLSessionCacheTimeout 600

httpd-vhosts.conf

Code:

<VirtualHost 192.168.1.76:443>

DocumentRoot "C:/xampp/htdocs/mysite/"
ServerName secure.mysite.com:443

SSLEngine on
SSLProtocol -all +TLSv1 +SSLv3
SSLCipherSuite HIGH:MEDIUM:!aNULL:+SHA1:+MD5:+HIGH:+MEDIUM

SSLCertificateFile conf/ssl.crt/secure.mysite.com.cer
SSLCertificateKeyFile conf/ssl.key/secure.mysite.com.rsa.key

SSLVerifyClient none
SSLProxyEngine off

BrowserMatch ".*CodeGear.*" nokeepalive ssl-unclean-shutdown downgrade-1.0 force-response-1.0
BrowserMatch ".*MSIE.*" nokeepalive ssl-unclean-shutdown downgrade-1.0 force-response-1.0

LogLevel trace6
ErrorLog "|bin/rotatelogs.exe logs/secure_mysite_com/%Y-%m-%d-error.log 86400"
CustomLog "|bin/rotatelogs.exe logs/secure_mysite_com/%Y-%m-%d-access.log 86400" combined

<directory "C:/xampp/htdocs/mysite/">
Options FollowSymLinks Includes
AllowOverride All
Order allow,deny
Allow from all
</directory>

# CGI #
<Directory "C:/xampp/htdocs/mysite/CodeGearSOAP_EXE/">
   SetHandler cgi-script
   AllowOverride None
   Options ExecCGI
</Directory>
</VirtualHost>

TRACE LOG OF ONE SOAP REQUEST

access.log

Code:

***.***.***.*** - - [27/Sep/2013:18:44:45 +0200] "POST /CodeGearSOAP_EXE/soap.exe HTTP/1.1" 200 4882 "-" "CodeGear SOAP 1.3"

error.log

Code:

[Fri Sep 27 18:44:45.307377 2013] [ssl:info] [pid 1304:tid 1848] [client ***.***.***.***:20395] AH01964: Connection to child 141 established (server secure.mysite.com:443)
[Fri Sep 27 18:44:45.307377 2013] [ssl:trace2] [pid 1304:tid 1848] ssl_engine_rand.c(123): Seeding PRNG with 144 bytes of entropy
[Fri Sep 27 18:44:45.307377 2013] [ssl:trace3] [pid 1304:tid 1848] ssl_engine_kernel.c(1841): [client ***.***.***.***:20395] OpenSSL: Handshake: start
[Fri Sep 27 18:44:45.307377 2013] [ssl:trace3] [pid 1304:tid 1848] ssl_engine_kernel.c(1849): [client ***.***.***.***:20395] OpenSSL: Loop: before/accept initialization
[Fri Sep 27 18:44:45.307377 2013] [core:trace6] [pid 1304:tid 1848] core_filters.c(527): [client ***.***.***.***:20395] core_output_filter: flushing because of FLUSH bucket
[Fri Sep 27 18:44:45.307377 2013] [ssl:trace4] [pid 1304:tid 1848] ssl_engine_io.c(1989): [client ***.***.***.***:20395] OpenSSL: read 11/11 bytes from BIO#126bbf0 [mem: 80152a0] (BIO dump follows)
[Fri Sep 27 18:44:45.307377 2013] [core:trace6] [pid 1304:tid 1848] core_filters.c(527): [client ***.***.***.***:20395] core_output_filter: flushing because of FLUSH bucket
[Fri Sep 27 18:44:45.307377 2013] [ssl:trace4] [pid 1304:tid 1848] ssl_engine_io.c(1989): [client ***.***.***.***:20395] OpenSSL: read 157/157 bytes from BIO#126bbf0 [mem: 80152ae] (BIO dump follows)
[Fri Sep 27 18:44:45.307377 2013] [socache_shmcb:debug] [pid 1304:tid 1848] mod_socache_shmcb.c(512): AH00835: socache_shmcb_retrieve (0x35 -> subcache 21)
[Fri Sep 27 18:44:45.307377 2013] [socache_shmcb:debug] [pid 1304:tid 1848] mod_socache_shmcb.c(836): AH00849: match at idx=0, data=0
[Fri Sep 27 18:44:45.307377 2013] [socache_shmcb:debug] [pid 1304:tid 1848] mod_socache_shmcb.c(523): AH00836: leaving socache_shmcb_retrieve successfully
[Fri Sep 27 18:44:45.307377 2013] [ssl:trace2] [pid 1304:tid 1848] ssl_engine_kernel.c(1697): Inter-Process Session Cache: request=GET status=FOUND id=356A6FAB37A0E2729FBEEFAB028CA5C57F799A7F024CD6F037FAB7C9EB6C5010 (session reuse)
[Fri Sep 27 18:44:45.307377 2013] [ssl:debug] [pid 1304:tid 1848] ssl_engine_kernel.c(1960): [client ***.***.***.***:20395] AH02043: SSL virtual host for servername secure.mysite.com found
[Fri Sep 27 18:44:45.307377 2013] [ssl:trace3] [pid 1304:tid 1848] ssl_engine_kernel.c(1849): [client ***.***.***.***:20395] OpenSSL: Loop: SSLv3 read client hello A
[Fri Sep 27 18:44:45.307377 2013] [ssl:trace3] [pid 1304:tid 1848] ssl_engine_kernel.c(1849): [client ***.***.***.***:20395] OpenSSL: Loop: SSLv3 write server hello A
[Fri Sep 27 18:44:45.307377 2013] [ssl:trace3] [pid 1304:tid 1848] ssl_engine_kernel.c(1849): [client ***.***.***.***:20395] OpenSSL: Loop: SSLv3 write change cipher spec A
[Fri Sep 27 18:44:45.307377 2013] [ssl:trace3] [pid 1304:tid 1848] ssl_engine_kernel.c(1849): [client ***.***.***.***:20395] OpenSSL: Loop: SSLv3 write finished A
[Fri Sep 27 18:44:45.307377 2013] [core:trace6] [pid 1304:tid 1848] core_filters.c(527): [client ***.***.***.***:20395] core_output_filter: flushing because of FLUSH bucket
[Fri Sep 27 18:44:45.307377 2013] [ssl:trace3] [pid 1304:tid 1848] ssl_engine_kernel.c(1849): [client ***.***.***.***:20395] OpenSSL: Loop: SSLv3 flush data
[Fri Sep 27 18:44:45.307377 2013] [core:trace6] [pid 1304:tid 1848] core_filters.c(527): [client ***.***.***.***:20395] core_output_filter: flushing because of FLUSH bucket
[Fri Sep 27 18:44:45.307377 2013] [ssl:trace4] [pid 1304:tid 1848] ssl_engine_io.c(1989): [client ***.***.***.***:20395] OpenSSL: read 5/5 bytes from BIO#126bbf0 [mem: 80152a3] (BIO dump follows)
[Fri Sep 27 18:44:45.307377 2013] [core:trace6] [pid 1304:tid 1848] core_filters.c(527): [client ***.***.***.***:20395] core_output_filter: flushing because of FLUSH bucket
[Fri Sep 27 18:44:45.307377 2013] [ssl:trace4] [pid 1304:tid 1848] ssl_engine_io.c(1989): [client ***.***.***.***:20395] OpenSSL: read 1/1 bytes from BIO#126bbf0 [mem: 80152a8] (BIO dump follows)
[Fri Sep 27 18:44:45.307377 2013] [core:trace6] [pid 1304:tid 1848] core_filters.c(527): [client ***.***.***.***:20395] core_output_filter: flushing because of FLUSH bucket
[Fri Sep 27 18:44:45.307377 2013] [ssl:trace4] [pid 1304:tid 1848] ssl_engine_io.c(1989): [client ***.***.***.***:20395] OpenSSL: read 5/5 bytes from BIO#126bbf0 [mem: 80152a3] (BIO dump follows)
[Fri Sep 27 18:44:45.307377 2013] [core:trace6] [pid 1304:tid 1848] core_filters.c(527): [client ***.***.***.***:20395] core_output_filter: flushing because of FLUSH bucket
[Fri Sep 27 18:44:45.307377 2013] [ssl:trace4] [pid 1304:tid 1848] ssl_engine_io.c(1989): [client ***.***.***.***:20395] OpenSSL: read 48/48 bytes from BIO#126bbf0 [mem: 80152a8] (BIO dump follows)
[Fri Sep 27 18:44:45.307377 2013] [ssl:trace3] [pid 1304:tid 1848] ssl_engine_kernel.c(1849): [client ***.***.***.***:20395] OpenSSL: Loop: SSLv3 read finished A
[Fri Sep 27 18:44:45.307377 2013] [ssl:trace3] [pid 1304:tid 1848] ssl_engine_kernel.c(1845): [client ***.***.***.***:20395] OpenSSL: Handshake: done
[Fri Sep 27 18:44:45.307377 2013] [ssl:debug] [pid 1304:tid 1848] ssl_engine_kernel.c(1890): [client ***.***.***.***:20395] AH02041: Protocol: TLSv1, Cipher: AES128-SHA (128/128 bits)
[Fri Sep 27 18:44:45.307377 2013] [core:trace6] [pid 1304:tid 1848] core_filters.c(527): [client ***.***.***.***:20395] core_output_filter: flushing because of FLUSH bucket
[Fri Sep 27 18:44:45.307377 2013] [ssl:trace4] [pid 1304:tid 1848] ssl_engine_io.c(1989): [client ***.***.***.***:20395] OpenSSL: read 5/5 bytes from BIO#126bbf0 [mem: 80152a3] (BIO dump follows)
[Fri Sep 27 18:44:45.307377 2013] [core:trace6] [pid 1304:tid 1848] core_filters.c(527): [client ***.***.***.***:20395] core_output_filter: flushing because of FLUSH bucket
[Fri Sep 27 18:44:45.307377 2013] [ssl:trace4] [pid 1304:tid 1848] ssl_engine_io.c(1989): [client ***.***.***.***:20395] OpenSSL: read 544/544 bytes from BIO#126bbf0 [mem: 80152a8] (BIO dump follows)
[Fri Sep 27 18:44:45.307377 2013] [core:trace5] [pid 1304:tid 1848] protocol.c(625): [client ***.***.***.***:20395] Request received from client: POST /soap/SOAP.exe HTTP/1.1
[Fri Sep 27 18:44:45.307377 2013] [setenvif:trace2] [pid 1304:tid 1848] mod_setenvif.c(623): [client ***.***.***.***:20395] Setting nokeepalive
[Fri Sep 27 18:44:45.307377 2013] [setenvif:trace2] [pid 1304:tid 1848] mod_setenvif.c(623): [client ***.***.***.***:20395] Setting ssl-unclean-shutdown
[Fri Sep 27 18:44:45.307377 2013] [setenvif:trace2] [pid 1304:tid 1848] mod_setenvif.c(623): [client ***.***.***.***:20395] Setting downgrade-1.0
[Fri Sep 27 18:44:45.307377 2013] [setenvif:trace2] [pid 1304:tid 1848] mod_setenvif.c(623): [client ***.***.***.***:20395] Setting force-response-1.0
[Fri Sep 27 18:44:45.307377 2013] [ssl:debug] [pid 1304:tid 1848] ssl_engine_kernel.c(236): [client ***.***.***.***:20395] AH02034: Initial (No.1) HTTPS request received for child 141 (server secure.mysite.com:443)
[Fri Sep 27 18:44:45.307377 2013] [http:trace4] [pid 1304:tid 1848] http_request.c(300): [client ***.***.***.***:20395] Headers received from client:
[Fri Sep 27 18:44:45.307377 2013] [http:trace4] [pid 1304:tid 1848] http_request.c(303): [client ***.***.***.***:20395] MIME-Version: 1.0
[Fri Sep 27 18:44:45.307377 2013] [http:trace4] [pid 1304:tid 1848] http_request.c(303): [client ***.***.***.***:20395] SOAPAction: \\"urn:SoapServerIntf-ISoapServer#SoapCommand\\"
[Fri Sep 27 18:44:45.307377 2013] [http:trace4] [pid 1304:tid 1848] http_request.c(303): [client ***.***.***.***:20395] Content-Type: multipart/related; boundary=MIME_boundaryB0R9532143182121
[Fri Sep 27 18:44:45.307377 2013] [http:trace4] [pid 1304:tid 1848] http_request.c(303): [client ***.***.***.***:20395] User-Agent: CodeGear SOAP 1.3
[Fri Sep 27 18:44:45.307377 2013] [http:trace4] [pid 1304:tid 1848] http_request.c(303): [client ***.***.***.***:20395] Host: secure.mysite.com
[Fri Sep 27 18:44:45.307377 2013] [http:trace4] [pid 1304:tid 1848] http_request.c(303): [client ***.***.***.***:20395] Content-Length: 4672
[Fri Sep 27 18:44:45.307377 2013] [http:trace4] [pid 1304:tid 1848] http_request.c(303): [client ***.***.***.***:20395] Connection: Keep-Alive
[Fri Sep 27 18:44:45.307377 2013] [http:trace4] [pid 1304:tid 1848] http_request.c(303): [client ***.***.***.***:20395] Cache-Control: no-cache
[Fri Sep 27 18:44:45.307377 2013] [http:trace4] [pid 1304:tid 1848] http_request.c(303): [client ***.***.***.***:20395] Cookie: SS_STRINGHELINGUA=IT; __utma=10233637.1711321739.1377762381.1377762381.1377765561.2; __utmz=10233637.1377762381.1.1.utmcsr=(direct)|utmccn=(direct)|utmcmd=(none)
[Fri Sep 27 18:44:45.307377 2013] [authz_core:debug] [pid 1304:tid 1848] mod_authz_core.c(808): [client ***.***.***.***:20395] AH01628: authorization result: granted (no directives)
[Fri Sep 27 18:44:45.307377 2013] [core:trace3] [pid 1304:tid 1848] request.c(225): [client ***.***.***.***:20395] request authorized without authentication by access_checker_ex hook: /soap/SOAP.exe
[Fri Sep 27 18:44:45.307377 2013] [authz_core:debug] [pid 1304:tid 1848] mod_authz_core.c(808): [client ***.***.***.***:20395] AH01628: authorization result: granted (no directives)
[Fri Sep 27 18:44:45.307377 2013] [core:trace3] [pid 1304:tid 1848] request.c(225): [client ***.***.***.***:20395] request authorized without authentication by access_checker_ex hook: /soap/ISoapServer
[Fri Sep 27 18:44:45.307377 2013] [core:trace6] [pid 1304:tid 1848] core_filters.c(527): [client ***.***.***.***:20395] core_output_filter: flushing because of FLUSH bucket
[Fri Sep 27 18:44:45.307377 2013] [ssl:trace4] [pid 1304:tid 1848] ssl_engine_io.c(1989): [client ***.***.***.***:20395] OpenSSL: read 5/5 bytes from BIO#126bbf0 [mem: 80152a3] (BIO dump follows)
[Fri Sep 27 18:44:45.307377 2013] [core:trace6] [pid 1304:tid 1848] core_filters.c(527): [client ***.***.***.***:20395] core_output_filter: flushing because of FLUSH bucket
[Fri Sep 27 18:44:45.307377 2013] [ssl:trace4] [pid 1304:tid 1848] ssl_engine_io.c(1989): [client ***.***.***.***:20395] OpenSSL: read 4704/4704 bytes from BIO#126bbf0 [mem: 80152a8] (BIO dump follows)
[Fri Sep 27 18:44:45.400977 2013] [cgi:trace4] [pid 1304:tid 1848] util_script.c(519): [client ***.***.***.***:20395] Headers from script 'SOAP.exe':
[Fri Sep 27 18:44:45.400977 2013] [cgi:trace4] [pid 1304:tid 1848] util_script.c(522): [client ***.***.***.***:20395] Status: 200 OK
[Fri Sep 27 18:44:45.400977 2013] [cgi:trace1] [pid 1304:tid 1848] util_script.c(597): [client ***.***.***.***:20395] Status line from script 'SOAP.exe': Status
[Fri Sep 27 18:44:45.400977 2013] [cgi:trace4] [pid 1304:tid 1848] util_script.c(522): [client ***.***.***.***:20395] Content-Version: MIME-Version: 1.0
[Fri Sep 27 18:44:45.400977 2013] [cgi:trace4] [pid 1304:tid 1848] util_script.c(522): [client ***.***.***.***:20395] Content-Type: multipart/related; boundary=MIME_boundaryB0R9532143182121; start="<http://www.borland.com/rootpart.xml>"
[Fri Sep 27 18:44:45.400977 2013] [cgi:trace4] [pid 1304:tid 1848] util_script.c(522): [client ***.***.***.***:20395] Content-Length: 4882
[Fri Sep 27 18:44:45.400977 2013] [cgi:trace4] [pid 1304:tid 1848] util_script.c(522): [client ***.***.***.***:20395] Content:
[Fri Sep 27 18:44:45.400977 2013] [http:trace3] [pid 1304:tid 1848] http_filters.c(960): [client ***.***.***.***:20395] Response sent with status 200, headers:
[Fri Sep 27 18:44:45.400977 2013] [http:trace5] [pid 1304:tid 1848] http_filters.c(969): [client ***.***.***.***:20395] Date: Fri, 27 Sep 2013 16:44:45 GMT
[Fri Sep 27 18:44:45.400977 2013] [http:trace5] [pid 1304:tid 1848] http_filters.c(972): [client ***.***.***.***:20395] Server: Apache/2.4.2 (Win32) OpenSSL/1.0.1c PHP/5.4.4
[Fri Sep 27 18:44:45.400977 2013] [http:trace4] [pid 1304:tid 1848] http_filters.c(804): [client ***.***.***.***:20395] Content-Version: MIME-Version: 1.0
[Fri Sep 27 18:44:45.400977 2013] [http:trace4] [pid 1304:tid 1848] http_filters.c(804): [client ***.***.***.***:20395] Content:
[Fri Sep 27 18:44:45.400977 2013] [http:trace4] [pid 1304:tid 1848] http_filters.c(804): [client ***.***.***.***:20395] Content-Length: 4882
[Fri Sep 27 18:44:45.400977 2013] [http:trace4] [pid 1304:tid 1848] http_filters.c(804): [client ***.***.***.***:20395] Connection: close
[Fri Sep 27 18:44:45.400977 2013] [http:trace4] [pid 1304:tid 1848] http_filters.c(804): [client ***.***.***.***:20395] Content-Type: multipart/related; boundary=MIME_boundaryB0R9532143182121; start=\\"<http://www.borland.com/rootpart.xml>\\"
[Fri Sep 27 18:44:45.400977 2013] [ssl:trace4] [pid 1304:tid 1848] ssl_engine_io.c(1439): [client ***.***.***.***:20395] coalesce: have 0 bytes, adding 319 more
[Fri Sep 27 18:44:45.400977 2013] [core:trace6] [pid 1304:tid 1848] core_filters.c(527): [client ***.***.***.***:20395] core_output_filter: flushing because of FLUSH bucket
[Fri Sep 27 18:44:45.432177 2013] [core:trace6] [pid 1304:tid 1848] core_filters.c(527): [client ***.***.***.***:20395] core_output_filter: flushing because of FLUSH bucket
[Fri Sep 27 18:44:45.478978 2013] [core:trace6] [pid 1304:tid 1848] core_filters.c(527): [client ***.***.***.***:20395] core_output_filter: flushing because of FLUSH bucket
[Fri Sep 27 18:44:45.478978 2013] [core:trace6] [pid 1304:tid 1848] core_filters.c(527): [client ***.***.***.***:20395] core_output_filter: flushing because of FLUSH bucket
[Fri Sep 27 18:44:45.478978 2013] [ssl:debug] [pid 1304:tid 1848] ssl_engine_io.c(984): [client ***.***.***.***:20395] AH01999: Connection closed to child 141 with unclean shutdown (server secure.mysite.com:443)

Steffen
Moderator

Joined: 15 Oct 2005
Posts: 3093
Location: Hilversum, NL, EU

Posted: Sun 29 Sep '13 11:08 Post subject:

You have to upgrade to 2.4.3+, your issue is solved since 2.4.3, see www.apachelounge.com/viewtopic.php?t=4866 Steffen

skillsfactory

Joined: 27 Sep 2013
Posts: 11
Location: Italy

Posted: Sun 29 Sep '13 11:17 Post subject:

Thanks! but i can't upgrade... other solution?

admin
Site Admin

Joined: 15 Oct 2005
Posts: 692

Posted: Sun 29 Sep '13 11:24 Post subject:

Nope, no other solution.

skillsfactory

Joined: 27 Sep 2013
Posts: 11
Location: Italy

Posted: Sun 29 Sep '13 11:40 Post subject:

ok, thank you! are you sure that the problem I described is resolved by the update? you get it from the logs?

James Blond
Moderator

Joined: 19 Jan 2006
Posts: 7373
Location: Germany, Next to Hamburg

Posted: Sun 29 Sep '13 19:33 Post subject:

Why can't you just replace the apache binaries?

skillsfactory

Joined: 27 Sep 2013
Posts: 11
Location: Italy

Posted: Sun 29 Sep '13 19:56 Post subject:

the server hosts 10 sites, I'm afraid to break something XD

James Blond
Moderator

Joined: 19 Jan 2006
Posts: 7373
Location: Germany, Next to Hamburg

Posted: Sun 29 Sep '13 20:31 Post subject:

You could run the newer apache on a different port alias parallel running and see how it goes

skillsfactory

Joined: 27 Sep 2013
Posts: 11
Location: Italy

Posted: Sun 29 Sep '13 20:32 Post subject:

It is a good idea...

skillsfactory

Joined: 27 Sep 2013
Posts: 11
Location: Italy

Posted: Thu 03 Oct '13 13:51 Post subject:

I updated apache 2 days ago and the problem seems solved. Thank you all!

Topic: SSL Requests Stop working after a while

View previous topic :: View next topic

Forum Index -> Apache