httpd-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Ulf Wahlqvist <Ulf.Wahlqv...@cybercomgroup.com>
Subject [users@httpd] OCSP-validation fails
Date Tue, 17 Aug 2010 15:26:22 GMT
An incomplete version of this post has previously been posted in openssl-users@openssl.org
and modssl-users@modssl.org, but this post contains a lot more info. I didn't realize that
the appropriate list is users@httpd.apache.org

I'm trying to get Apache to do Client certificate verification with OCSP-validation.
It works without OCSP, but OCSP-validation fails when I turn it on.
The error is "OCSP_check_validity:status too old", but that doesn't make sense because the
clocks are within 2 seconds. 

I'm not using the OCSP-responder address in the certificates "Authority Info Access" (http://sithsocsp.trust.telia.com),
because it is not reachable from my system. However, the same responder is reachable using
another address (http://ocsp.trust.telia.com).

I have verified that if I use openssl directly from command line it will verify OK. 
>openssl ocsp -issuer /usr/local/apache2/conf/SITHS_CA_v3.cer -CAfile /usr/local/apache2/conf/SITHS_CA_v3.cer
-cert /mnt/download/uwcert.cer -text -url http://ocsp.trust.telia.com
.
.
Response verify OK
/mnt/download/uwcert.cer: good
        This Update: Jul 29 10:43:41 2010 GMT
        Next Update: Jul 30 10:43:45 2010 GMT

** my config *************************************************************************************************************************************


[root@fedoragui crl]# uname -a
Linux fedoragui.mydomain.com 2.6.33.5-112.fc13.i686 #1 SMP Thu May 27 03:11:56 UTC 2010 i686
i686 i386 GNU/Linux

[root@fedoragui logs]# httpd -v
Server version: Apache/2.3.6 (Unix)
Server built:   Jul 16 2010 15:31:39

[root@fedoragui logs]# openssl version
OpenSSL 1.0.0a-fips 1 Jun 2010

./configure --enable-ssl

Finally I made some progress. I think that there is something wrong here. 

/ulfW

** Tests ****************************************************************************************************************************************

CASE 1/ If I set:
SSLOCSPDefaultResponder http://ocsp.trust.telia.com
SSLOCSPOverrideResponder on

The validation will fail with "SSL Library Error: error:2707307F:OCSP routines:OCSP_check_validity:status
too old" 

CASE 2/ If I set:
SSLOCSPDefaultResponder http://ocsp.trust.telia.com

The validation of the first cert in the chain will succeed but the second will fail with "(110)Connection
timed out: could not connect to OCSP responder 'sithsocsp.trust.telia.com'". This is the expected
behavior because my computer does not have access to sithsocsp.trust.telia.com.

CASE 3/ If I set:
SSLOCSPDefaultResponder http://ocsp.trust.telia.com

- Try to authenticate - It will fail as in 2 above.
- Do NOT close the browser (IE, by the way)
- set:
SSLOCSPDefaultResponder http://ocsp.trust.telia.com
SSLOCSPOverrideResponder on
- restart using apachectl graceful
- Retry to authenticate - It will now SUCCEED!

======= CASE 1 ======================================================================================================================
[Tue Aug 17 14:14:54.744503 2010] [debug] [pid 7465:tid 3063937904] ssl_util_ocsp.c(79): [client
10.0.2.2:3988] connecting to OCSP responder 'ocsp.trust.telia.com'
[Tue Aug 17 14:14:54.751235 2010] [debug] [pid 7465:tid 3063937904] ssl_util_ocsp.c(105):
[client 10.0.2.2:3988] sending request to OCSP responder
[Tue Aug 17 14:14:54.775514 2010] [debug] [pid 7465:tid 3063937904] ssl_util_ocsp.c(209):
[client 10.0.2.2:3988] OCSP response header: Date: Tue, 17 Aug 2010 14:14:54 GMT
[Tue Aug 17 14:14:54.775657 2010] [debug] [pid 7465:tid 3063937904] ssl_util_ocsp.c(209):
[client 10.0.2.2:3988] OCSP response header: Server: Apache
[Tue Aug 17 14:14:54.775693 2010] [debug] [pid 7465:tid 3063937904] ssl_util_ocsp.c(209):
[client 10.0.2.2:3988] OCSP response header: Content-Length: 1264
[Tue Aug 17 14:14:54.775727 2010] [debug] [pid 7465:tid 3063937904] ssl_util_ocsp.c(209):
[client 10.0.2.2:3988] OCSP response header: Connection: close
[Tue Aug 17 14:14:54.775760 2010] [debug] [pid 7465:tid 3063937904] ssl_util_ocsp.c(209):
[client 10.0.2.2:3988] OCSP response header: Content-Type: application/ocsp-response
[Tue Aug 17 14:14:54.775794 2010] [debug] [pid 7465:tid 3063937904] ssl_util_ocsp.c(252):
[client 10.0.2.2:3988] OCSP response: got 1264 bytes, 1264 total
[Tue Aug 17 14:14:54.775861 2010] [debug] [pid 7465:tid 3063937904] ssl_util_ocsp.c(235):
[client 10.0.2.2:3988] OCSP response: got EOF
[Tue Aug 17 14:14:54.778718 2010] [error] [pid 7465:tid 3063937904] SSL Library Error: error:2707307F:OCSP
routines:OCSP_check_validity:status too old
[Tue Aug 17 14:14:54.779238 2010] [error] [pid 7465:tid 3063937904] [client 10.0.2.2:3988]
Certificate Verification: Error (50): application verification failure
[Tue Aug 17 14:14:54.785691 2010] [info] [pid 7465:tid 3063937904] [client 10.0.2.2:3988]
SSL library error 1 in handshake (server fedoragui.mydomain.com:443)
[Tue Aug 17 14:14:54.786404 2010] [info] [pid 7465:tid 3063937904] SSL Library Error: error:140890B2:SSL
routines:SSL3_GET_CLIENT_CERTIFICATE:no certificate returned

======= CASE 2 ======================================================================================================================
[Tue Aug 17 14:20:04.701759 2010] [debug] [pid 7621:tid 3063937904] ssl_util_ocsp.c(79): [client
10.0.2.2:4015] connecting to OCSP responder 'ocsp.trust.telia.com'
[Tue Aug 17 14:20:04.708379 2010] [debug] [pid 7621:tid 3063937904] ssl_util_ocsp.c(105):
[client 10.0.2.2:4015] sending request to OCSP responder
[Tue Aug 17 14:20:05.179220 2010] [debug] [pid 7621:tid 3063937904] ssl_util_ocsp.c(209):
[client 10.0.2.2:4015] OCSP response header: Date: Tue, 17 Aug 2010 14:20:04 GMT
[Tue Aug 17 14:20:05.179350 2010] [debug] [pid 7621:tid 3063937904] ssl_util_ocsp.c(209):
[client 10.0.2.2:4015] OCSP response header: Server: Apache
[Tue Aug 17 14:20:05.179388 2010] [debug] [pid 7621:tid 3063937904] ssl_util_ocsp.c(209):
[client 10.0.2.2:4015] OCSP response header: Content-Length: 1264
[Tue Aug 17 14:20:05.179422 2010] [debug] [pid 7621:tid 3063937904] ssl_util_ocsp.c(209):
[client 10.0.2.2:4015] OCSP response header: Connection: close
[Tue Aug 17 14:20:05.179457 2010] [debug] [pid 7621:tid 3063937904] ssl_util_ocsp.c(209):
[client 10.0.2.2:4015] OCSP response header: Content-Type: application/ocsp-response
[Tue Aug 17 14:20:05.179491 2010] [debug] [pid 7621:tid 3063937904] ssl_util_ocsp.c(252):
[client 10.0.2.2:4015] OCSP response: got 1264 bytes, 1264 total
[Tue Aug 17 14:20:05.179640 2010] [debug] [pid 7621:tid 3063937904] ssl_util_ocsp.c(235):
[client 10.0.2.2:4015] OCSP response: got EOF
[Tue Aug 17 14:20:05.204281 2010] [debug] [pid 7621:tid 3063937904] ssl_util_ocsp.c(79): [client
10.0.2.2:4015] connecting to OCSP responder 'sithsocsp.trust.telia.com'
[Tue Aug 17 14:20:26.204360 2010] [error] [pid 7621:tid 3063937904] [client 10.0.2.2:4015]
(110)Connection timed out: could not connect to OCSP responder 'sithsocsp.trust.telia.com'
[Tue Aug 17 14:20:26.204654 2010] [error] [pid 7621:tid 3063937904] [client 10.0.2.2:4015]
Certificate Verification: Error (50): application verification failure
[Tue Aug 17 14:20:26.205540 2010] [info] [pid 7621:tid 3063937904] [client 10.0.2.2:4015]
SSL library error 1 in handshake (server fedoragui.mydomain.com:443)
[Tue Aug 17 14:20:26.209204 2010] [info] [pid 7621:tid 3053448048] [client 10.0.2.2:4023]
Connection to child 65 established (server fedoragui.mydomain.com:443)
[Tue Aug 17 14:20:26.206197 2010] [info] [pid 7621:tid 3063937904] SSL Library Error: error:140890B2:SSL
routines:SSL3_GET_CLIENT_CERTIFICATE:no certificate returned

======= CASE 3 ======================================================================================================================
[Tue Aug 17 14:20:04.701759 2010] [debug] [pid 7621:tid 3063937904] ssl_util_ocsp.c(79): [client
10.0.2.2:4015] connecting to OCSP responder 'ocsp.trust.telia.com'
[Tue Aug 17 14:20:04.708379 2010] [debug] [pid 7621:tid 3063937904] ssl_util_ocsp.c(105):
[client 10.0.2.2:4015] sending request to OCSP responder
[Tue Aug 17 14:20:05.179220 2010] [debug] [pid 7621:tid 3063937904] ssl_util_ocsp.c(209):
[client 10.0.2.2:4015] OCSP response header: Date: Tue, 17 Aug 2010 14:20:04 GMT
[Tue Aug 17 14:20:05.179350 2010] [debug] [pid 7621:tid 3063937904] ssl_util_ocsp.c(209):
[client 10.0.2.2:4015] OCSP response header: Server: Apache
[Tue Aug 17 14:20:05.179388 2010] [debug] [pid 7621:tid 3063937904] ssl_util_ocsp.c(209):
[client 10.0.2.2:4015] OCSP response header: Content-Length: 1264
[Tue Aug 17 14:20:05.179422 2010] [debug] [pid 7621:tid 3063937904] ssl_util_ocsp.c(209):
[client 10.0.2.2:4015] OCSP response header: Connection: close
[Tue Aug 17 14:20:05.179457 2010] [debug] [pid 7621:tid 3063937904] ssl_util_ocsp.c(209):
[client 10.0.2.2:4015] OCSP response header: Content-Type: application/ocsp-response
[Tue Aug 17 14:20:05.179491 2010] [debug] [pid 7621:tid 3063937904] ssl_util_ocsp.c(252):
[client 10.0.2.2:4015] OCSP response: got 1264 bytes, 1264 total
[Tue Aug 17 14:20:05.179640 2010] [debug] [pid 7621:tid 3063937904] ssl_util_ocsp.c(235):
[client 10.0.2.2:4015] OCSP response: got EOF
[Tue Aug 17 14:20:05.204281 2010] [debug] [pid 7621:tid 3063937904] ssl_util_ocsp.c(79): [client
10.0.2.2:4015] connecting to OCSP responder 'sithsocsp.trust.telia.com'
[Tue Aug 17 14:20:26.204360 2010] [error] [pid 7621:tid 3063937904] [client 10.0.2.2:4015]
(110)Connection timed out: could not connect to OCSP responder 'sithsocsp.trust.telia.com'
[Tue Aug 17 14:20:26.204654 2010] [error] [pid 7621:tid 3063937904] [client 10.0.2.2:4015]
Certificate Verification: Error (50): application verification failure
[Tue Aug 17 14:20:26.205540 2010] [info] [pid 7621:tid 3063937904] [client 10.0.2.2:4015]
SSL library error 1 in handshake (server fedoragui.mydomain.com:443)
[Tue Aug 17 14:20:26.209204 2010] [info] [pid 7621:tid 3053448048] [client 10.0.2.2:4023]
Connection to child 65 established (server fedoragui.mydomain.com:443)
[Tue Aug 17 14:20:26.206197 2010] [info] [pid 7621:tid 3063937904] SSL Library Error: error:140890B2:SSL
routines:SSL3_GET_CLIENT_CERTIFICATE:no certificate returned
.
.
.
<<RESTART OF Apache with SSLOCSPOverrideResponder on>>
.
.
.
[Tue Aug 17 14:21:19.487041 2010] [debug] [pid 7752:tid 3063937904] ssl_util_ocsp.c(79): [client
10.0.2.2:4027] connecting to OCSP responder 'ocsp.trust.telia.com'
[Tue Aug 17 14:21:19.493743 2010] [debug] [pid 7752:tid 3063937904] ssl_util_ocsp.c(105):
[client 10.0.2.2:4027] sending request to OCSP responder
[Tue Aug 17 14:21:19.518465 2010] [debug] [pid 7752:tid 3063937904] ssl_util_ocsp.c(209):
[client 10.0.2.2:4027] OCSP response header: Date: Tue, 17 Aug 2010 14:21:19 GMT
[Tue Aug 17 14:21:19.518609 2010] [debug] [pid 7752:tid 3063937904] ssl_util_ocsp.c(209):
[client 10.0.2.2:4027] OCSP response header: Server: Apache
[Tue Aug 17 14:21:19.518646 2010] [debug] [pid 7752:tid 3063937904] ssl_util_ocsp.c(209):
[client 10.0.2.2:4027] OCSP response header: Content-Length: 1264
[Tue Aug 17 14:21:19.518680 2010] [debug] [pid 7752:tid 3063937904] ssl_util_ocsp.c(209):
[client 10.0.2.2:4027] OCSP response header: Connection: close
[Tue Aug 17 14:21:19.518714 2010] [debug] [pid 7752:tid 3063937904] ssl_util_ocsp.c(209):
[client 10.0.2.2:4027] OCSP response header: Content-Type: application/ocsp-response
[Tue Aug 17 14:21:19.518748 2010] [debug] [pid 7752:tid 3063937904] ssl_util_ocsp.c(252):
[client 10.0.2.2:4027] OCSP response: got 1264 bytes, 1264 total
[Tue Aug 17 14:21:19.518893 2010] [debug] [pid 7752:tid 3063937904] ssl_util_ocsp.c(235):
[client 10.0.2.2:4027] OCSP response: got EOF
[Tue Aug 17 14:21:19.542930 2010] [debug] [pid 7752:tid 3063937904] ssl_util_ocsp.c(79): [client
10.0.2.2:4027] connecting to OCSP responder 'ocsp.trust.telia.com'
[Tue Aug 17 14:21:19.549988 2010] [debug] [pid 7752:tid 3063937904] ssl_util_ocsp.c(105):
[client 10.0.2.2:4027] sending request to OCSP responder
[Tue Aug 17 14:21:19.574396 2010] [debug] [pid 7752:tid 3063937904] ssl_util_ocsp.c(209):
[client 10.0.2.2:4027] OCSP response header: Date: Tue, 17 Aug 2010 14:21:18 GMT
[Tue Aug 17 14:21:19.574487 2010] [debug] [pid 7752:tid 3063937904] ssl_util_ocsp.c(209):
[client 10.0.2.2:4027] OCSP response header: Server: Apache
[Tue Aug 17 14:21:19.574524 2010] [debug] [pid 7752:tid 3063937904] ssl_util_ocsp.c(209):
[client 10.0.2.2:4027] OCSP response header: Content-Length: 1265
[Tue Aug 17 14:21:19.574667 2010] [debug] [pid 7752:tid 3063937904] ssl_util_ocsp.c(209):
[client 10.0.2.2:4027] OCSP response header: Connection: close
[Tue Aug 17 14:21:19.574704 2010] [debug] [pid 7752:tid 3063937904] ssl_util_ocsp.c(209):
[client 10.0.2.2:4027] OCSP response header: Content-Type: application/ocsp-response
[Tue Aug 17 14:21:19.574739 2010] [debug] [pid 7752:tid 3063937904] ssl_util_ocsp.c(252):
[client 10.0.2.2:4027] OCSP response: got 1265 bytes, 1265 total
[Tue Aug 17 14:21:19.574809 2010] [debug] [pid 7752:tid 3063937904] ssl_util_ocsp.c(235):
[client 10.0.2.2:4027] OCSP response: got EOF
[Tue Aug 17 14:21:19.596860 2010] [debug] [pid 7752:tid 3063937904] mod_socache_shmcb.c(478):
socache_shmcb_store (0x4e -> subcache 14)
[Tue Aug 17 14:21:19.600846 2010] [debug] [pid 7752:tid 3063937904] mod_socache_shmcb.c(786):
insert happened at idx=0, data=(0:32)
[Tue Aug 17 14:21:19.601348 2010] [debug] [pid 7752:tid 3063937904] mod_socache_shmcb.c(791):
finished insert, subcache: idx_pos/idx_used=0/1, data_pos/data_used=0/1502
[Tue Aug 17 14:21:19.601601 2010] [debug] [pid 7752:tid 3063937904] mod_socache_shmcb.c(493):
leaving socache_shmcb_store successfully
[Tue Aug 17 14:21:19.601935 2010] [debug] [pid 7752:tid 3063937904] ssl_engine_kernel.c(1970):
[client 10.0.2.2:4027] Connection: Client IP: 10.0.2.2, Protocol: TLSv1, Cipher: RC4-MD5 (128/128
bits)
[Tue Aug 17 14:21:19.602811 2010] [debug] [pid 7752:tid 3063937904] ssl_engine_kernel.c(242):
[client 10.0.2.2:4027] Initial (No.1) HTTPS request received for child 64 (server fedoragui.mydomain.com:443)
[Tue Aug 17 14:21:19.603759 2010] [debug] [pid 7752:tid 3063937904] mod_authz_core.c(720):
[client 10.0.2.2:4027] authorization result of Require all granted: granted
[Tue Aug 17 14:21:19.609594 2010] [debug] [pid 7752:tid 3063937904] mod_authz_core.c(720):
[client 10.0.2.2:4027] authorization result of <RequireAny>: granted




---------------------------------------------------------------------
The official User-To-User support forum of the Apache HTTP Server Project.
See <URL:http://httpd.apache.org/userslist.html> for more info.
To unsubscribe, e-mail: users-unsubscribe@httpd.apache.org
   "   from the digest: users-digest-unsubscribe@httpd.apache.org
For additional commands, e-mail: users-help@httpd.apache.org


Mime
View raw message