#1
  1. No Profile Picture
    Registered User
    Devshed Newbie (0 - 499 posts)

    Join Date
    Sep 2013
    Posts
    2
    Rep Power
    0

    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)
  2. #2
  3. No Profile Picture
    Registered User
    Devshed Newbie (0 - 499 posts)

    Join Date
    Sep 2013
    Posts
    2
    Rep Power
    0
    Solution

    upgrade Apache to 2.4.3+

    configurations added:
    AcceptFilter http none
    AcceptFilter https none
    EnableSendfile off
    EnableMMAP off

IMN logo majestic logo threadwatch logo seochat tools logo