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: Select all
AcceptFilter http none
# AcceptFilter https none (try to uncomment, but ssl stop work)
EnableMMAP off
EnableSendfile off
httpd-ssl.conf
- Code: Select all
Listen 443
SSLPassPhraseDialog builtin
SSLSessionCache "shmcb:logs/ssl.scache(512000)"
SSLSessionCacheTimeout 600
httpd-vhosts.conf
- Code: Select all
<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: Select all
***.***.***.*** - - [27/Sep/2013:18:44:45 +0200] "POST /CodeGearSOAP_EXE/soap.exe HTTP/1.1" 200 4882 "-" "CodeGear SOAP 1.3"
error.log
- Code: Select all
[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)