Bug 499052 - rhcs80beta TPS and mod_nss with NSSOCSP has ssl errors and unable to use agent service
rhcs80beta TPS and mod_nss with NSSOCSP has ssl errors and unable to use agen...
Status: CLOSED WORKSFORME
Product: Dogtag Certificate System
Classification: Community
Component: Mod_NSS (Show other bugs)
unspecified
All Linux
medium Severity medium
: ---
: ---
Assigned To: Christina Fu
Chandrasekar Kannan
:
Depends On: 500877
Blocks: 507664
  Show dependency treegraph
 
Reported: 2009-05-04 20:06 EDT by Marc Sauton
Modified: 2015-01-04 18:38 EST (History)
12 users (show)

See Also:
Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
: 507664 (view as bug list)
Environment:
Last Closed: 2012-07-11 13:14:12 EDT
Type: ---
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)
ssltap output for client auth with nssocsp on - Re-negotiation handshake failed: Not accepted by client!? (5.44 KB, text/html)
2009-05-19 18:26 EDT, Marc Sauton
no flags Details
test nssocsp with nss-3.12.3.99.3-1.el5_3.1 (2.65 KB, text/plain)
2009-06-08 20:41 EDT, Marc Sauton
no flags Details

  None (edit)
Description Marc Sauton 2009-05-04 20:06:39 EDT
Description of problem:

may be several issues or may be I do not have the correct configuration, not sure, but effects are like below:

1- TPS start apparently "OK", listener seems up:

lsof -i :7889
COMMAND     PID    USER   FD   TYPE DEVICE SIZE NODE NAME
httpd.wor 10806    root    5u  IPv4  35484       TCP *:7889 (LISTEN)
httpd.wor 10837 pkiuser    5u  IPv4  35484       TCP *:7889 (LISTEN)

but /var/log/pki-tps/error_log is showing:

[Mon May 04 15:39:52 2009] [info] Using nickname Server-Cert cert-pki-tps.
[Mon May 04 15:39:52 2009] [error] Certificate not verified: 'Server-Cert cert-pki-tps'
[Mon May 04 15:39:52 2009] [error] SSL Library Error: -8071 The OCSP server experienced an internal error


2- then, it is impossible to use the agent/admin pages, has popup error window in browser / FF2.0 (Mac and Fedora):

"
Could not establish an encrypted connection because your certificate was rejected by
<hostname>. Error Code: -12271. 
"

/var/log/pki-tps/error_log is showing at that moment:

[Mon May 04 12:53:00 2009] [error] Bad remote server certificate: -8071
[Mon May 04 12:53:00 2009] [error] SSL Library Error: -8071 The OCSP server experienced an internal error
[Mon May 04 12:53:00 2009] [info] SSL input filter read failed.
[Mon May 04 12:53:00 2009] [error] SSL Library Error: -8071 The OCSP server experienced an internal error
[Mon May 04 12:53:00 2009] [info] Connection to child 4 closed (server ms2-cs8-1-64.sjc.redhat.com:7889, client 10.14.51.34)
[Mon May 04 12:53:00 2009] [info] Connection to child 5 established (server ms2-cs8-1-64.sjc.redhat.com:7889, client 10.14.51.34)
[Mon May 04 12:53:00 2009] [error] Bad remote server certificate: -8071
[Mon May 04 12:53:00 2009] [error] SSL Library Error: -8071 The OCSP server experienced an internal error
[Mon May 04 12:53:00 2009] [info] SSL input filter read failed.
[Mon May 04 12:53:00 2009] [error] SSL Library Error: -8071 The OCSP server experienced an internal error
[Mon May 04 12:53:00 2009] [info] Connection to child 5 closed (server ms2-cs8-1-64.sjc.redhat.com:7889, client 10.14.51.34) 



environment information:

Version-Release number of selected component (if applicable):

Red Hat Enterprise Linux Server release 5.3 (Tikanga)

Linux ms2-cs8-1-64.sjc.redhat.com 2.6.18-128.el5xen #1 SMP Wed Dec 17 12:01:40 EST 2008 x86_64 x86_64 x86_64 GNU/Linux

alternatives --config java
...
*+ 2           /usr/lib/jvm/jre-1.6.0-openjdk.x86_64/bin/java

have

-rw-r--r-- 1 root    root    87993 May  4 11:42 mod_nss-1.0.8-1.el5idm.x86_64.rpm
from
https://brewweb.devel.redhat.com//rpminfo?rpmID=1299621

and tomcat from last week:
-rw-r--r-- 1 root    root    28315 May  1 12:01 tomcatjss-1.1.0-13.el5idm.noarch.rpm
also from brew

other rpm's
pki-native-tools-8.0.0-10.beta
pki-selinux-8.0.0-4.beta
redhat-pki-tps-ui-8.0.0-16.beta
pki-ra-8.0.0-16.beta
redhat-pki-ca-ui-8.0.0-12.beta
pki-java-tools-8.0.0-11.beta
pki-ca-8.0.0-12.beta
mod_revocator-1.0.2-1.el5pki
redhat-pki-ocsp-ui-8.0.0-7.beta
pki-ocsp-8.0.0-12.beta
redhat-pki-console-ui-8.0.0-9.beta
redhat-pki-common-ui-8.0.0-12.beta
redhat-pki-kra-ui-8.0.0-7.beta
redhat-pki-tks-ui-8.0.0-6.beta
pki-tks-8.0.0-12.beta
pkinit-nss-0.7.6-1.el5
pki-console-8.0.0-8.beta
pki-setup-8.0.0-12.beta
pki-kra-8.0.0-12.beta
pki-tps-8.0.0-18.beta
pki-util-8.0.0-10.beta
pki-common-8.0.0-10.beta
redhat-pki-ra-ui-8.0.0-10.beta


How reproducible:
always


Steps to Reproduce:

1. configure httpd.conf to remove revocator statements:

diff /etc/pki-tps/httpd.conf /etc/pki-tps/httpd.conf.orig
267c267
< # LoadModule rev_module  /etc/httpd/modules/mod_rev.so
---
> LoadModule rev_module  /etc/httpd/modules/mod_rev.so
1057c1057
< # Include /var/lib/pki-tps/conf/revocator.conf
---
> Include /var/lib/pki-tps/conf/revocator.conf 


2. configure /etc/pki-tps/nss.conf, uses CA's OCSP internal responder:, and Ca signing certificate:
...
Listen 0.0.0.0:7889

Listen 0.0.0.0:7890
...
NSSEnforceValidCerts on
...
<VirtualHost _default_:7889>
...
NSSOCSP on
NSSOCSPDefaultResponder on
NSSOCSPDefaultURL http://ms2-cs8-1-64.sjc.redhat.com:9180/ca/ocsp
NSSOCSPDefaultName caCert
</VirtualHost>


3. verify certicates in NSS TPS db:

caCert is in /var/lib/pki-tps/alias/ :

certutil -L -d /var/lib/pki-tps/alias

Certificate Nickname                                         Trust Attributes
                                                             SSL,S/MIME,JAR/XPI

subsystemCert cert-pki-tps                                   u,u,u
ocspSigningCert cert-pki-ocsp                                CT,C,C
Server-Cert cert-pki-tps                                     u,u,u
auditSigningCert cert-pki-tps                                u,u,u
caCert                                                       CT,C,C


certutil -L -d /var/lib/pki-tps/alias -n "caCert"
Certificate:
    Data:
        Version: 3 (0x2)
        Serial Number: 1 (0x1)
        Signature Algorithm: PKCS #1 SHA-1 With RSA Encryption
        Issuer: "CN=Certificate Authority,O=rhcs80beta 9443 rootca ms2cs81 20
            090424"
        Validity:
            Not Before: Fri Apr 24 19:24:04 2009
            Not After : Thu Apr 14 19:24:04 2011
        Subject: "CN=Certificate Authority,O=rhcs80beta 9443 rootca ms2cs81 2
            0090424"
...

certutil -V -d /var/lib/pki-tps/alias -n "Server-Cert cert-pki-tps" -u V
certutil: certificate is valid

certutil -V -d /var/lib/pki-tps/alias -n "caCert" -u O
certutil: certificate is valid 


4. web browsers configuration:

- FF2.0.0.19 on Fedora with first admin / agent certificate generated by CA configuration

- FF2.0.0.20 on Mac with second agent certificate, to be revoked later for the revocation test

- Verification is set to use OCSP to validate only certificates that specify an OCSP service URL

- both agent certificates are verified successfully in the browser's certificate manager 


5. restart TPS

service pki-tps restart
Stopping pki-tps:
process already stopped
Starting pki-tps:
==> debug <==
                                                           [  OK  ]
Mon May  4 15:39:50 PDT 2009 - TPS wizard: starting up
Mon May  4 15:39:51 PDT 2009 - TPS wizard: start up complete

==> error_log <==
[Mon May 04 15:39:51 2009] [notice] SELinux policy enabled; httpd running as context root:system_r:pki_tps_t:s0
[Mon May 04 15:39:51 2009] [info] Initializing SSL Session Cache of size 10000. SSL2 timeout = 100, SSL3/TLS timeout = 86400.
[Mon May 04 15:39:51 2009] [info] OCSP is enabled.
[Mon May 04 15:39:51 2009] [info] Init: Initializing (virtual) servers for SSL
[Mon May 04 15:39:51 2009] [info] Configuring server for SSL protocol
[Mon May 04 15:39:51 2009] [debug] nss_engine_init.c(594): Enabling SSL3
[Mon May 04 15:39:51 2009] [debug] nss_engine_init.c(599): Enabling TLS
[Mon May 04 15:39:51 2009] [debug] nss_engine_init.c(770): Configuring permitted SSL ciphers [-des,-desede3,-rc2,-rc2export,-rc4,-rc4export,+rsa_3des_sha,-rsa_des_56_sha,+rsa_des_sha,-rsa_nul
l_md5,-rsa_null_sha,-rsa_rc2_40_md5,+rsa_rc4_128_md5,-rsa_rc4_128_sha,-rsa_rc4_40_md5,-rsa_rc4_56_sha,-fortezza,-fortezza_rc4_128_sha,-fortezza_null,-fips_des_sha,+fips_3des_sha,-rsa_aes_128_
sha,-rsa_aes_256_sha,+ecdhe_ecdsa_aes_256_sha]
[Mon May 04 15:39:51 2009] [info] Using nickname Server-Cert cert-pki-tps.
[Mon May 04 15:39:51 2009] [error] Certificate not verified: 'Server-Cert cert-pki-tps'
[Mon May 04 15:39:51 2009] [error] SSL Library Error: -8071 The OCSP server experienced an internal error
[Mon May 04 15:39:51 2009] [info] Configuring server for SSL protocol
[Mon May 04 15:39:51 2009] [debug] nss_engine_init.c(594): Enabling SSL3[Mon May 04 15:39:51 2009] [debug] nss_engine_init.c(599): Enabling TLS[Mon May 04 15:39:51 2009] [debug] nss_engine_init.c(770): Configuring permitted SSL ciphers [-des,-desede3,-rc2,-rc2export,-rc4,-rc4export,+rsa_3des_sha,-rsa_des_56_sha,+rsa_des_sha,-rsa_nul
l_md5,-rsa_null_sha,-rsa_rc2_40_md5,+rsa_rc4_128_md5,-rsa_rc4_128_sha,-rsa_rc4_40_md5,-rsa_rc4_56_sha,-fortezza,-fortezza_rc4_128_sha,-fortezza_null,-fips_des_sha,+fips_3des_sha,-rsa_aes_128_
sha,-rsa_aes_256_sha,+ecdhe_ecdsa_aes_256_sha]
[Mon May 04 15:39:51 2009] [info] Using nickname Server-Cert cert-pki-tps.
[Mon May 04 15:39:51 2009] [error] Certificate not verified: 'Server-Cert cert-pki-tps'
[Mon May 04 15:39:51 2009] [error] SSL Library Error: -8071 The OCSP server experienced an internal error
[Mon May 04 15:39:51 2009] [info] Server: Apache/2.2.3, Interface: mod_nss/2.2.3, Library: NSS/3.12.3 Basic ECC
[Mon May 04 15:39:51 2009] [debug] ../src/modules/tps/mod_tps.cpp(274): Entering mod_tps_initialize - init count is [1][Mon May 04 15:39:51 2009] [info] The TPS plugin was successfully loaded![Mon May 04 15:39:51 2009] [info] Shutting down SSL Session ID Cache

pki-tps (pid 10806) is running ...


==> debug <==
Mon May  4 15:39:52 PDT 2009 - TPS wizard: starting up

==> error_log <==
[Mon May 04 15:39:52 2009] [info] Initializing SSL Session Cache of size 10000. SSL2 timeout = 100, SSL3/TLS timeout = 86400.
[Mon May 04 15:39:52 2009] [info] Server: Apache/2.2.3, Interface: mod_nss/2.2.3, Library: NSS/3.12.3 Basic ECC
[Mon May 04 15:39:52 2009] [debug] ../src/modules/tps/mod_tps.cpp(274): Entering mod_tps_initialize - init count is [2]
[Mon May 04 15:39:52 2009] [info] The TPS plugin was successfully loaded!
[Mon May 04 15:39:52 2009] [debug] ../src/modules/tps/mod_tps.cpp(350): mod_tps_initialize - pid is [10806] - post config already done once - additional config will be done in init_child
[Mon May 04 15:39:52 2009] [notice] Apache/2.2.3 (Red Hat) mod_nss/2.2.3 NSS/3.12.3 Basic ECC mod_perl/2.0.4 Perl/v5.8.8 configured -- resuming normal operations
[Mon May 04 15:39:52 2009] [info] Server built: Nov 12 2008 07:10:24
[Mon May 04 15:39:52 2009] [debug] worker.c(1740): AcceptMutex: sysvsem (default: sysvsem)
[Mon May 04 15:39:52 2009] [info] OCSP is enabled.[Mon May 04 15:39:52 2009] [info] Configuring server for SSL protocol[Mon May 04 15:39:52 2009] [debug] nss_engine_init.c(594): Enabling SSL3
[Mon May 04 15:39:52 2009] [debug] nss_engine_init.c(599): Enabling TLS
[Mon May 04 15:39:52 2009] [debug] nss_engine_init.c(770): Configuring permitted SSL ciphers [-des,-desede3,-rc2,-rc2export,-rc4,-rc4export,+rsa_3des_sha,-rsa_des_56_sha,+rsa_des_sha,-rsa_nul
l_md5,-rsa_null_sha,-rsa_rc2_40_md5,+rsa_rc4_128_md5,-rsa_rc4_128_sha,-rsa_rc4_40_md5,-rsa_rc4_56_sha,-fortezza,-fortezza_rc4_128_sha,-fortezza_null,-fips_des_sha,+fips_3des_sha,-rsa_aes_128_
sha,-rsa_aes_256_sha,+ecdhe_ecdsa_aes_256_sha]
[Mon May 04 15:39:52 2009] [info] Using nickname Server-Cert cert-pki-tps.
[Mon May 04 15:39:52 2009] [error] Certificate not verified: 'Server-Cert cert-pki-tps'
[Mon May 04 15:39:52 2009] [error] SSL Library Error: -8071 The OCSP server experienced an internal error[Mon May 04 15:39:52 2009] [info] Configuring server for SSL protocol[Mon May 04 15:39:52 2009] [debug] nss_engine_init.c(594): Enabling SSL3
[Mon May 04 15:39:52 2009] [debug] nss_engine_init.c(599): Enabling TLS
[Mon May 04 15:39:52 2009] [debug] nss_engine_init.c(770): Configuring permitted SSL ciphers [-des,-desede3,-rc2,-rc2export,-rc4,-rc4export,+rsa_3des_sha,-rsa_des_56_sha,+rsa_des_sha,-rsa_nul
l_md5,-rsa_null_sha,-rsa_rc2_40_md5,+rsa_rc4_128_md5,-rsa_rc4_128_sha,-rsa_rc4_40_md5,-rsa_rc4_56_sha,-fortezza,-fortezza_rc4_128_sha,-fortezza_null,-fips_des_sha,+fips_3des_sha,-rsa_aes_128_
sha,-rsa_aes_256_sha,+ecdhe_ecdsa_aes_256_sha]
[Mon May 04 15:39:52 2009] [info] Using nickname Server-Cert cert-pki-tps.
[Mon May 04 15:39:52 2009] [error] Certificate not verified: 'Server-Cert cert-pki-tps'
[Mon May 04 15:39:52 2009] [error] SSL Library Error: -8071 The OCSP server experienced an internal error
    Unsecure Port              = http://ms2-cs8-1-64.sjc.redhat.com:7888/cgi-bin/so/enroll.cgi
                                 (ESC Security Officer Enrollment)
    Unsecure Port              = http://ms2-cs8-1-64.sjc.redhat.com:7888/cgi-bin/home/index.cgi
                                 (ESC Phone Home)
    Secure Clientauth Port     = https://ms2-cs8-1-64.sjc.redhat.com:7889/cgi-bin/sow/welcome.cgi
                                 (ESC Security Officer Workstation)
    Secure Clientauth Port     = https://ms2-cs8-1-64.sjc.redhat.com:7889/tus
                                 (TPS Roles - Operator/Administrator/Agent)
    Secure Non-Clientauth Port = https://ms2-cs8-1-64.sjc.redhat.com:7890/cgi-bin/so/enroll.cgi
                                 (ESC Security Officer Enrollment)
    Secure Non-Clientauth Port = https://ms2-cs8-1-64.sjc.redhat.com:7890/cgi-bin/home/index.cgi
                                 (ESC Phone Home)


6. browse to TPS agent pages fails, gets popup window with error message:
"
Could not establish an encrypted connection because your certificate was rejected by
<hostname>. Error Code: -12271.
OK
"

CA debug log has apparent good ocsp requests and responses:

[04/May/2009:12:47:13][http-9180-Processor25]: CMSServlet:service() uri = /ca/ocsp
[04/May/2009:12:47:13][http-9180-Processor25]: CMSServlet: caOCSP start to service.
...
[04/May/2009:12:47:13][http-9180-Processor25]: OCSPServlet: MGMwYQIBADA+MDwwOjAJBgUrDgMCGgUABBQ42Cd9DqmWP4ZZL1d7LkpvjEKkDAQU
EVOWJke9IQ3iU8zR9//Q0odtOq0CARwwHDAaBgkrBgEFBQcwAQQEDTALBgkrBgEF
BQcwAQE=
[04/May/2009:12:47:13][http-9180-Processor25]: Serial Number: 28
[04/May/2009:12:47:13][http-9180-Processor25]: OCSPServlet: OCSP Response Size:
[04/May/2009:12:47:13][http-9180-Processor25]: OCSPServlet: 2453
[04/May/2009:12:47:13][http-9180-Processor25]: OCSPServlet: OCSP Response Data:
[04/May/2009:12:47:13][http-9180-Processor25]: OCSPServlet: MIIJkQoBAKCCCYowggmGBgkrBgEFBQcwAQEEggl3MIIJczCBwqADAgEAoVcwVTEw
...
[04/May/2009:12:47:13][http-9180-Processor25]: Serial Number: 28 Status: com.netscape.cmsutil.ocsp.GoodInfo
[04/May/2009:12:47:13][http-9180-Processor25]: CMSServlet: curDate=Mon May 04 12:47:13 PDT 2009 id=caOCSP time=15 


but /var/log/pki-tps/error_log has:

[Mon May 04 12:53:00 2009] [error] Bad remote server certificate: -8071
[Mon May 04 12:53:00 2009] [error] SSL Library Error: -8071 The OCSP server experienced an internal error
[Mon May 04 12:53:00 2009] [info] SSL input filter read failed.
[Mon May 04 12:53:00 2009] [error] SSL Library Error: -8071 The OCSP server experienced an internal error
[Mon May 04 12:53:00 2009] [info] Connection to child 4 closed (server ms2-cs8-1-64.sjc.redhat.com:7889, client 10.14.51.34)
[Mon May 04 12:53:00 2009] [info] Connection to child 5 established (server ms2-cs8-1-64.sjc.redhat.com:7889, client 10.14.51.34)
[Mon May 04 12:53:00 2009] [error] Bad remote server certificate: -8071
[Mon May 04 12:53:00 2009] [error] SSL Library Error: -8071 The OCSP server experienced an internal error
[Mon May 04 12:53:00 2009] [info] SSL input filter read failed.
[Mon May 04 12:53:00 2009] [error] SSL Library Error: -8071 The OCSP server experienced an internal error
[Mon May 04 12:53:00 2009] [info] Connection to child 5 closed (server ms2-cs8-1-64.sjc.redhat.com:7889, client 10.14.51.34)
Comment 1 Marc Sauton 2009-05-04 20:07:14 EDT
related to bz 211612
Comment 2 Rob Crittenden 2009-05-05 09:58:14 EDT
NSSOCSPDefaultName needs to be set to the nickname of the certificate used to sign the OCSP response, in this case ocspSigningCert cert-pki-ocsp. Your trust on this cert looks ok. The minimum you need to start the server is C,,. You might need CT,, if you do client auth in mod_nss.

So set this in nss.conf:

NSSOCSPDefaultName "ocspSigningCert cert-pki-ocsp"

And set NSSEnforceValidCerts on

If the Server-Cert itself isn't passing validation then there is no point in doing any further requests.
Comment 3 Marc Sauton 2009-05-15 15:20:59 EDT
ok, works for me.

did some more tests related to Issue-Tracker 295625 request around mod_nss and ocsp, I likely did not have the proper ocsp signing cert from the ca's responder in the previous notes for NSSOCSPDefaultName, my mistake.

The httpd's server certificate status is correctly verified using either the CA's embedded or standalone OCSP responders.

tested with

Linux ms2-cs8-1-64.sjc.redhat.com 2.6.18-128.el5xen #1 SMP Wed Dec 17 12:01:40 EST 2008 x86_64 x86_64 x86_64 GNU/Linux
RHEL 5.3
pki-ca-8.0.0-13.beta
pki-ocsp-8.0.0-13.beta
nss-3.12.2.0-2.el5

and

Linux ms2-cs8-2-64.sjc.redhat.com 2.6.18-128.el5xen #1 SMP Wed Dec 17 12:01:40 EST 2008 x86_64 x86_64 x86_64 GNU/Linux
RHEL 5.3
httpd-2.2.3-22.el5
mod_nss-1.0.8-1.el5idm
nss-3.12.2.0-2.el5


2 examples below for httpd, will re-do later with a TPS instance on RHCS80beta

--------------------------------------------------------------------
example 1 - with CA's embedded ocsp responder 

get OCSP Signing Certificate from CA (caocsp nickname)
ca signing cert also installed and trusted

certutil -A -d /etc/httpd/alias -n caocsp -t CTu,Cu,Cu -a -i ../ca.ocsp.signing.crt
certutil -L -d .

Certificate Nickname                                         Trust Attributes
                                                             SSL,S/MIME,JAR/XPI

Server-Cert                                                  u,u,u
Server-Cert7443                                              u,u,u
ca                                                           CT,C,C
alpha                                                        u,pu,u
caocsp                                                       CT,C,C


and using the CA's embedded ocsp responder uri:
vi /etc/httpd/conf.d/7443.conf
Listen 7443
NSSEnforceValidCerts on
...
NSSOCSP on
NSSOCSPDefaultResponder on
NSSOCSPDefaultURL http://ms2-cs8-1-64.sjc.redhat.com:9180/ca/ocsp
NSSOCSPDefaultName caocsp

on httpd server:
service httpd restart
Stopping httpd:                                            [  OK  ]
Starting httpd:                                            [  OK  ]
[root@ms2-cs8-2-64 alias]# [Thu May 14 17:36:28 2009] [notice] caught SIGTERM, shutting down
[Thu May 14 17:36:29 2009] [notice] SELinux policy enabled; httpd running as context root:system_r:httpd_t
[Thu May 14 17:36:29 2009] [notice] suEXEC mechanism enabled (wrapper: /usr/sbin/suexec)
[Thu May 14 17:36:29 2009] [notice] Digest: generating secret for digest authentication ...
[Thu May 14 17:36:29 2009] [notice] Digest: done
[Thu May 14 17:36:29 2009] [notice] Apache/2.2.3 (Red Hat) configured -- resuming normal operations


ca debug, ssl server was verified:
[14/May/2009:17:36:36][http-9180-Processor23]: Serial Number: 35 Status: com.netscape.cmsutil.ocsp.GoodInfo


on ca's agent pages, revoke httpd ssl server cert, verify crl

on httpd server:
service httpd restart
Stopping httpd:                                            [  OK  ]
Starting httpd:                                            [FAILED]
[root@ms2-cs8-2-64 alias]# [Thu May 14 17:37:59 2009] [error] Certificate not verified: 'Server-Cert7443'
[Thu May 14 17:37:59 2009] [error] SSL Library Error: -8180 Certificate has been revoked
[Thu May 14 17:37:59 2009] [error] Unable to verify certificate 'Server-Cert7443'. Add "NSSEnforceValidCerts off" to nss.conf so the server can start until the problem can be resolved.
[Thu May 14 17:37:59 2009] [notice] caught SIGTERM, shutting down
[Thu May 14 17:37:59 2009] [notice] SELinux policy enabled; httpd running as context root:system_r:httpd_t
[Thu May 14 17:37:59 2009] [notice] suEXEC mechanism enabled (wrapper: /usr/sbin/suexec)

on ca's agent pages, off hold httpd ssl server cert, verify valid cert and crl

on httpd server:
service httpd restart
Stopping httpd:                                            [FAILED]
Starting httpd:                                            [  OK  ]
[root@ms2-cs8-2-64 alias]# [Thu May 14 17:38:32 2009] [notice] SELinux policy enabled; httpd running as context root:system_r:httpd_t
[Thu May 14 17:38:32 2009] [notice] suEXEC mechanism enabled (wrapper: /usr/sbin/suexec)
[Thu May 14 17:38:33 2009] [notice] Digest: generating secret for digest authentication ...
[Thu May 14 17:38:33 2009] [notice] Digest: done
[Thu May 14 17:38:33 2009] [notice] Apache/2.2.3 (Red Hat) configured -- resuming normal operations


visit https url to get valid content:
https://10.14.54.8:7443/



--------------------------------------------------------------------
example 2 - with standalone ocsp responder 

OCSP Signing Certificate from OCSP instance (ocsp nickname)
ca signing cert also installed and trusted

on httpd:

certutil -L -d /etc/httpd/alias

Certificate Nickname                                         Trust Attributes
                                                             SSL,S/MIME,JAR/XPI

Server-Cert                                                  u,u,u
Server-Cert7443                                              u,u,u
ca                                                           CT,C,C
alpha                                                        u,pu,u
ocsp                                                         CT,C,C


and using  the standalone ocsp responder uri:
vi /etc/httpd/conf.d/7443.conf

Listen 7443
NSSEnforceValidCerts on
...
NSSOCSP on
NSSOCSPDefaultResponder on
NSSOCSPDefaultURL http://ms2-cs8-1-64.sjc.redhat.com:11180/ocsp/ee/ocsp
NSSOCSPDefaultName caocsp


service httpd restart
Stopping httpd:                                            [FAILED]
Starting httpd:                                            [  OK  ]


on OCSP instance:
[15/May/2009:10:36:49][http-11180-Processor19]: Serial Number: 35 Status: com.netscape.cmsutil.ocsp.GoodInfo
[15/May/2009:10:36:49][http-11180-Processor19]: CMSServlet: curDate=Fri May 15 10:36:49 PDT 2009 id=ocspOCSP time=15


then on CA, revoke httpd ssl server cert
update crl on ca agent pages, verify in ocsp agent pages

on httpd server:
service httpd restart
Stopping httpd:                                            [FAILED]
Starting httpd:                                            [FAILED]
[root@ms2-cs8-2-64 alias]# [Fri May 15 10:42:23 2009] [error] Certificate not verified: 'Server-Cert7443'
[Fri May 15 10:42:23 2009] [error] SSL Library Error: -8180 Certificate has been revoked
[Fri May 15 10:42:23 2009] [error] Unable to verify certificate 'Server-Cert7443'. Add "NSSEnforceValidCerts off" to nss.conf so the server can start until the problem can be resolved.

then on CA, off hold httpd ssl server cert, valid
update crl on ca agent pages, verify in ocsp agent pages

on httpd server:
service httpd restart
Stopping httpd:                                            [FAILED]
Starting httpd:                                            [  OK  ]
[root@ms2-cs8-2-64 alias]# [Fri May 15 10:44:42 2009] [notice] SELinux policy enabled; httpd running as context root:system_r:httpd_t
[Fri May 15 10:44:42 2009] [notice] suEXEC mechanism enabled (wrapper: /usr/sbin/suexec)
[Fri May 15 10:44:42 2009] [notice] Digest: generating secret for digest authentication ...
[Fri May 15 10:44:42 2009] [notice] Digest: done
[Fri May 15 10:44:42 2009] [notice] Apache/2.2.3 (Red Hat) configured -- resuming normal operations
Comment 4 Marc Sauton 2009-05-15 15:34:53 EDT
extra note to be confirmed:
in my tests, with:
NSSOCSPDefaultResponder off

the aia ocsp uri from cert is used as expected, and the following seem not used
NSSOCSPDefaultURL 
NSSOCSPDefaultName 


In the doc at 
http://directory.fedoraproject.org/docs/mod_nss.html 
for NSSOCSPDefaultResponder and NSSOCSPDefaultName

We indicate "This is required when NSSOCSPDefaultResponder is enabled"
and for example in issue-Tracker 295625, a customer configured like this:

#   Online Certificate Status Protocol (OCSP).
#   Verify that certificates have not been revoked before accepting them.
NSSOCSP on

#   Use a default OCSP responder. If enabled this will be used regardless
#   of whether one is included in a client certificate. Note that the
#   server certificate is verified during startup.
NSSOCSPDefaultResponder off
NSSOCSPDefaultURL http://x.x.x.x:x/ocsp/ee/ocsp
NSSOCSPDefaultName "x Certificate Authority"

It looks like this customer wanted to specify NSSOCSPDefaultURL and (a wrong) NSSOCSPDefaultName, even though NSSOCSPDefaultResponder is off.

If there is some possible confusion, I would suggest the following text change to the doc at
http://directory.fedoraproject.org/docs/mod_nss.html


NSSOCSPDefaultURL URL

from:

The URL that NSS will use for the OCSP default responder. This is required when NSSOCSPDefaultResponder is enabled.

to:

The URL that NSS will use for the OCSP default responder. This is required when NSSOCSPDefaultResponder is enabled, and not used otherwise.


and:

NSSOCSPDefaultName

from:

The nickname of the certificate that NSS will use to validate the response from the default OCSP responder. This is required when NSSOCSPDefaultResponder is enabled. 

to:

The nickname of the certificate that NSS will use to validate the response from the default OCSP responder, usually an OCSP signing certificate.
This is required when NSSOCSPDefaultResponder is enabled, and not used otherwise.


make sense?
Comment 5 Marc Sauton 2009-05-19 18:23:19 EDT
there is something bizarre, I may be wrong, but I cannot get client auth to work if NSSOCSP is on.

This was set originally to validate tps with mod_nss.

I am trying client auth with a valid client cert, with or without nssocsp.
If I turn on NSSOCSP I get the -122771 in an alert popup window in browser and -8071 httpd error log.

Testing the status of the server cert with nss ocsp (and no client auth tests) works as expected, I can fail the httpd's start if the httpd's ssl server cert is revoked, so I suppose I somehow have a correct NSSOCSP configuration.

I also see this in the virtual server http error log upon failed client auth:
Tue May 19 13:43:02 2009] [error] Re-negotiation handshake failed: Not accepted by client!?
(in mod_nss/nss_engine_kernel.c)

while the more general http log shows:
[Tue May 19 13:43:02 2009] [error] Bad remote server certificate: -8071
[Tue May 19 13:43:02 2009] [error] SSL Library Error: -8071 The OCSP server experienced an internal error

the ssltap just show some alert before ending in or just after the ssl handshake.
About to update bz 499052
Comment 6 Marc Sauton 2009-05-19 18:26:36 EDT
Created attachment 344723 [details]
ssltap output for client auth with nssocsp on - Re-negotiation handshake failed: Not accepted by client!?
Comment 7 Marc Sauton 2009-05-19 18:29:20 EDT
test env was:

ms2-cs8-2-64
Red Hat Enterprise Linux Server release 5.3 (Tikanga)
Linux ms2-cs8-2-64.sjc.redhat.com 2.6.18-128.el5xen #1 SMP Wed Dec 17 12:01:40 EST 2008 x86_64 x86_64 x86_64 GNU/Linux

nss-3.12.2.0-2.el5
mod_nss-1.0.8-1.el5idm
httpd-2.2.3-22.el5
Comment 8 Marc Sauton 2009-05-19 18:44:13 EDT
The browser (FF2 or FF3) 's verification (or validation) setting seem to have no effects, with either "Do not use OCSP for certificate verification" or "Use OCSP to validate only certificates that specify an OCSP service"
My tests certs were generated by a RHCS80beta instance, with OCSP URI AIA extension
In FF3, seleting or unselecting "When an OCSP server connection fails, treat the certificate as invalid" has no effect to this test., same if I unselect OCSP validation in FF3
Comment 9 Rob Crittenden 2009-05-20 11:45:20 EDT
I was able to reproduce this and my CA isn't logging the client OCSP request at all.

I'm having a tough time tracing this through NSS but it appears to be failing in  *hcv1->trySendAndReceiveFcn (pkix_pl_HttpDefaultClient_TrySendAndReceiveFcn). Using ssltap I was able to verify that it is attempting to do a POST to the OCSP server and I can see the POST in the access log on the CA but nothing in the debug log at all.

The NSPR error that the NSS OCSP client is getting is -5961 (PR_CONNECT_RESET_ERROR)

So it seems like the CA is rejecting the request.
Comment 20 Chandrasekar Kannan 2009-05-21 17:21:44 EDT
> But then, why can't I see any TCP traffic from the test httpd's system to a
> CA's embedded OCSP responder or to a separate standalone OCSP responder when
> NSSOCSP is set to on?

> Ok, weird. I would have sworn I was getting hits in the access log of CS but
> I'm not.

If the OCSP response is cached, it will use that and not hit the server.
Is this what you are seeing ?.
Comment 21 Rob Crittenden 2009-05-21 17:24:23 EDT
No this is the first request against a freshly started server so there is no cache yet. And it is definitely trying to make an outbound connection.
Comment 22 Rob Crittenden 2009-05-22 14:59:13 EDT
I think this is a bug in NSS. I filed this: 

https://bugzilla.mozilla.org/show_bug.cgi?id=494459
Comment 23 Andrew Wnuk 2009-05-25 18:26:46 EDT
Possibly solved in 3.12.4.
See https://bugzilla.mozilla.org/show_bug.cgi?id=470055 for more details.
Comment 51 Kai Engert (:kaie) 2009-06-08 19:49:35 EDT
Marc, may I ask for a short summary?

The primary question and purpose of my test request was:
"Do the new packages still fix the bug reported in here?"

Thanks for answering this.

I would like to propose to use the comment feature for summaries.
If you want to provide lots of details about your experiments, I propose to attach them.
This increases readability of bugs.

So, did you get any new bugs, that you didn't get with the previous test package?
Could it be a server issue? Cert changed?
Do you want to file separate bugs?
Comment 52 Marc Sauton 2009-06-08 20:41:41 EDT
Created attachment 346945 [details]
test nssocsp with nss-3.12.3.99.3-1.el5_3.1

answer to comment 51: yes.

adding details about test in new attachment, and copy and paste from comment 50:

Client auth with mod_nss-1.0.8-1.el5idm on httpd-2.2.3-22.el5, doing end user
cert status verification using pki-ca-8.0.0-14.beta works ok for me.

Note there is a different behavior in httpd and browser after a httpd restart
when a client cert is revoked, example details below, steps 4 and 6.
Comment 66 Rob Crittenden 2009-07-06 10:02:23 EDT
If NSSOCSP is set then all mod_nss does is call:

CERT_EnableOCSPChecking(CERT_GetDefaultCertDB());

If NSSOCSPDefaultResponder is set too then it also calls:

CERT_SetOCSPDefaultResponder(CERT_GetDefaultCertDB(), ocspurl, ocspnickname);

I wonder what the bottom of the stack looks like.

Chandra, can you tell which cert is being verified over and over again?
Comment 67 Chandrasekar Kannan 2009-07-06 10:10:58 EDT
(In reply to comment #66)
> 
> Chandra, can you tell which cert is being verified over and over again?  

Yes, it is the root CA cert. I see a gazillion verifications for this one..
Serial Number: 1 Status: com.netscape.cmsutil.ocsp.GoodInfo
Comment 68 Chandrasekar Kannan 2009-07-06 10:18:05 EDT
A copy of the root ca cert, sub ca cert, tps server cert are here ..
http://pastebin.test.redhat.com/12752
Comment 69 Marc Sauton 2009-07-06 16:12:30 EDT
seem to work ok for me when testing NSSOCSP and Apache (not TPS), no apparent ca seg fault nor excessive logging, with or without AIA override:

ca and sub ca on el5.3 x86_64
pki-ca-8.0.0-15.beta

web server on el4 i386
nss-3.12.3.99.3-1.el4.test.2
nspr-4.7.4-1.el4.test.2
httpd-2.0.52-41.ent

on web server:
grep -i ocsp /etc/httpd/conf.d/7443.conf
# NSSOCSP off
NSSOCSP on
# NSSOCSPDefaultResponder on
# NSSOCSPDefaultURL http://ms2-cs8-1-64.sjc.redhat.com:8180/ca/ocsp
# NSSOCSPDefaultName subca1ocsp
# stand alone ocsp
# NSSOCSPDefaultURL http://ms2-cs8-1-64.sjc.redhat.com:11180/ocsp/ee/ocsp
# NSSOCSPDefaultName ocsp

example with client cert revoked:

FF 3.5b4 on F11:
Forbidden
You don't have permission to access /securearea/ on this server.

httpd log:
[Mon Jul 06 13:02:19 2009] [error] Re-negotiation handshake failed: Client verification failed

subordinate CA debug log:
[06/Jul/2009:13:02:18][http-8180-Processor21]: Serial Number: 6 Status: com.netscape.cmsutil.ocsp.RevokedInfo
[06/Jul/2009:13:02:18][http-8180-Processor21]: CMSServlet: curDate=Mon Jul 06 13:02:18 PDT 2009 id=caOCSP time=11


and ok when client cert is off hold, sub ca log:

[06/Jul/2009:13:09:11][http-8180-Processor25]: Serial Number: 6 Status: com.netscape.cmsutil.ocsp.GoodInfo
[06/Jul/2009:13:09:11][http-8180-Processor25]: CMSServlet: curDate=Mon Jul 06 13:09:11 PDT 2009 id=caOCSP time=10

httpd log:
10.14.51.46 - - [06/Jul/2009:13:09:11 -0700] "GET /securearea/ HTTP/1.1" 200 36
Comment 70 Jack Magne 2009-07-06 17:37:58 EDT
OK:

Was able to pretty much reproduce on my F8 box by configuring as suggested. Here is a sample print out of the gbd stack trace:

I believe there is something of a pattern emerging :)

(gdb) where
#0  0x0012d402 in __kernel_vsyscall ()
#1  0x00508a8b in poll () from /lib/libc.so.6
#2  0x006ff1ca in ?? () from /usr/lib/libnspr4.so
#3  0x0070013f in ?? () from /usr/lib/libnspr4.so
#4  0x006e630d in PR_Recv () from /usr/lib/libnspr4.so
#5  0x00689ba9 in ?? () from /usr/lib/libnss3.so
#6  0x0067bbe8 in ?? () from /usr/lib/libnss3.so
#7  0x0067be4d in ?? () from /usr/lib/libnss3.so
#8  0x005b0b51 in ?? () from /usr/lib/libnss3.so
#9  0x005b11f3 in ?? () from /usr/lib/libnss3.so
#10 0x005b4ae6 in CERT_VerifyCert () from /usr/lib/libnss3.so
#11 0x005af807 in CERT_VerifyOCSPResponseSignature () from /usr/lib/libnss3.so
#12 0x005b13d3 in ?? () from /usr/lib/libnss3.so
#13 0x005b4ae6 in CERT_VerifyCert () from /usr/lib/libnss3.so
#14 0x005af807 in CERT_VerifyOCSPResponseSignature () from /usr/lib/libnss3.so
#15 0x005b13d3 in ?? () from /usr/lib/libnss3.so
#16 0x005b4ae6 in CERT_VerifyCert () from /usr/lib/libnss3.so
#17 0x005af807 in CERT_VerifyOCSPResponseSignature () from /usr/lib/libnss3.so
#18 0x005b13d3 in ?? () from /usr/lib/libnss3.so
#19 0x005b4ae6 in CERT_VerifyCert () from /usr/lib/libnss3.so
#20 0x005af807 in CERT_VerifyOCSPResponseSignature () from /usr/lib/libnss3.so
#21 0x005b13d3 in ?? () from /usr/lib/libnss3.so
#22 0x005b4ae6 in CERT_VerifyCert () from /usr/lib/libnss3.so
#23 0x005af807 in CERT_VerifyOCSPResponseSignature () from /usr/lib/libnss3.so
#24 0x005b13d3 in ?? () from /usr/lib/libnss3.so
#25 0x005b4ae6 in CERT_VerifyCert () from /usr/lib/libnss3.so
#26 0x005af807 in CERT_VerifyOCSPResponseSignature () from /usr/lib/libnss3.so
#27 0x005b13d3 in ?? () from /usr/lib/libnss3.so
#28 0x005b4ae6 in CERT_VerifyCert () from /usr/lib/libnss3.so
#29 0x005af807 in CERT_VerifyOCSPResponseSignature () from /usr/lib/libnss3.so
#30 0x005b13d3 in ?? () from /usr/lib/libnss3.so
#31 0x005b4ae6 in CERT_VerifyCert () from /usr/lib/libnss3.so
#32 0x005af807 in CERT_VerifyOCSPResponseSignature () from /usr/lib/libnss3.so
#33 0x005b13d3 in ?? () from /usr/lib/libnss3.so
#34 0x005b4ae6 in CERT_VerifyCert () from /usr/lib/libnss3.so
#35 0x005af807 in CERT_VerifyOCSPResponseSignature () from /usr/lib/libnss3.so
#36 0x005b13d3 in ?? () from /usr/lib/libnss3.so
#37 0x005b4ae6 in CERT_VerifyCert () from /usr/lib/libnss3.so
#38 0x005af807 in CERT_VerifyOCSPResponseSignature () from /usr/lib/libnss3.so
#39 0x005b13d3 in ?? () from /usr/lib/libnss3.so
#40 0x005b4ae6 in CERT_VerifyCert () from /usr/lib/libnss3.so
#41 0x005af807 in CERT_VerifyOCSPResponseSignature () from /usr/lib/libnss3.so
#42 0x005b13d3 in ?? () from /usr/lib/libnss3.so
#43 0x005b4ae6 in CERT_VerifyCert () from /usr/lib/libnss3.so
#44 0x005af807 in CERT_VerifyOCSPResponseSignature () from /usr/lib/libnss3.so
#45 0x005b13d3 in ?? () from /usr/lib/libnss3.so
#46 0x005b4ae6 in CERT_VerifyCert () from /usr/lib/libnss3.so
#47 0x005af807 in CERT_VerifyOCSPResponseSignature () from /usr/lib/libnss3.so
#48 0x005b13d3 in ?? () from /usr/lib/libnss3.so
#49 0x005b4ae6 in CERT_VerifyCert () from /usr/lib/libnss3.so
---Type <return> to continue, or q <return> to quit---  
#50 0x005af807 in CERT_VerifyOCSPResponseSignature () from /usr/lib/libnss3.so
#51 0x005b13d3 in ?? () from /usr/lib/libnss3.so
#52 0x005b4ae6 in CERT_VerifyCert () from /usr/lib/libnss3.so
#53 0x005af807 in CERT_VerifyOCSPResponseSignature () from /usr/lib/libnss3.so
#54 0x005b13d3 in ?? () from /usr/lib/libnss3.so
#55 0x005b4ae6 in CERT_VerifyCert () from /usr/lib/libnss3.so
#56 0x005af807 in CERT_VerifyOCSPResponseSignature () from /usr/lib/libnss3.so
#57 0x005b13d3 in ?? () from /usr/lib/libnss3.so
Comment 71 Jack Magne 2009-07-06 23:37:34 EDT
More detailed stack:

(gdb) where
#0  0x0012d402 in __kernel_vsyscall ()
#1  0x00518a8b in poll () from /lib/libc.so.6
#2  0x007481ca in ?? () from /usr/lib/libnspr4.so
#3  0x0074913f in ?? () from /usr/lib/libnspr4.so
#4  0x0072f30d in PR_Recv () from /usr/lib/libnspr4.so
#5  0x006d51be in pkix_pl_Socket_Recv (rcvSock=0xbacc16f0, buf=0xbb4d3348, 
    capacity=1024, pBytesRead=0xbfb5e514, plContext=0x0)
    at pkix_pl_socket.c:1055
#6  0x006c29e1 in pkix_pl_HttpDefaultClient_RecvHdr (client=0xbaaa9d18, 
    pKeepGoing=0xbfb5e588, plContext=0x0) at pkix_pl_httpdefaultclient.c:830
#7  0x006c3255 in pkix_pl_HttpDefaultClient_Dispatch (client=0xbaaa9d18, 
    plContext=0x0) at pkix_pl_httpdefaultclient.c:1101
#8  0x006c408b in pkix_pl_HttpDefaultClient_TrySendAndReceive (
    request=0xbaaa9d18, http_response_code=0xbfb5e6a2, 
    http_response_content_type=0x0, http_response_headers=0x0, 
    http_response_data=0xbfb5e69c, http_response_data_len=0xbfb5e698, 
    pPollDesc=0x0, pSECReturn=0xbfb5e65c, plContext=0x0)
    at pkix_pl_httpdefaultclient.c:1440
#9  0x006c464f in pkix_pl_HttpDefaultClient_TrySendAndReceiveFcn (
    request=0xbaaa9d18, pPollDesc=0x0, http_response_code=0xbfb5e6a2, 
    http_response_content_type=0x0, http_response_headers=0x0, 
    http_response_data=0xbfb5e69c, http_response_data_len=0xbfb5e698)
    at pkix_pl_httpdefaultclient.c:1654
#10 0x005c14c5 in fetchOcspHttpClientV1 (arena=0x0, hcv1=0x6fefe4, 
    location=0xbb16a838 "http://dhcp-170.sjc.redhat.com:9180/ca/ocsp", 
    encodedRequest=0xbad248c0) at ocsp.c:3339
#11 0x005c1702 in ocsp_GetEncodedOCSPResponseFromRequest (arena=0x0, 
    request=0xbb4d2b38, 
    location=0xbb16a838 "http://dhcp-170.sjc.redhat.com:9180/ca/ocsp", 
    time=1246937738000000, addServiceLocator=0, pwArg=0x0, pRequest=0xbfb5e7c0)
    at ocsp.c:3471
#12 0x005c1831 in ocsp_GetEncodedOCSPResponseForSingleCert (arena=0x0, 
    certID=0xbb4d12e0, singleCert=0xb9c0cd40, 
    location=0xbb16a838 "http://dhcp-170.sjc.redhat.com:9180/ca/ocsp", 
    time=1246937738000000, addServiceLocator=0, pwArg=0x0, pRequest=0xbfb5e7c0)
    at ocsp.c:3517
#13 0x005c3208 in ocsp_GetOCSPStatusFromNetwork (handle=0xb9bf0170, 
    certID=0xbb4d12e0, cert=0xb9c0cd40, time=1246937738000000, pwArg=0x0, 
    certIDWasConsumed=0xbfb5e834, rv_ocsp=0xbfb5e830) at ocsp.c:4844
#14 0x005c307e in CERT_CheckOCSPStatus (handle=0xb9bf0170, cert=0xb9c0cd40, 
    time=1246937738000000, pwArg=0x0) at ocsp.c:4754
#15 0x005c8089 in CERT_VerifyCert (handle=0xb9bf0170, cert=0xb9c0cd40, 
    checkSig=1, certUsage=certUsageAnyCA, t=1246937738000000, wincx=0x0, 
    log=0x0) at certvfy.c:1503
#16 0x005c1f9f in CERT_VerifyOCSPResponseSignature (response=0xbb4cd2f0, 
    handle=0xb9bf0170, pwArg=0x0, pSignerCert=0xbfb5e96c, issuer=0xb9c1cf58)
    at ocsp.c:3887
#17 0x005c328b in ocsp_GetOCSPStatusFromNetwork (handle=0xb9bf0170, 
    certID=0xbb4ccad8, cert=0xb9c0cd40, time=1246937738000000, pwArg=0x0, 
    certIDWasConsumed=0xbfb5e9e4, rv_ocsp=0xbfb5e9e0) at ocsp.c:4875
#18 0x005c307e in CERT_CheckOCSPStatus (handle=0xb9bf0170, cert=0xb9c0cd40, 
---Type <return> to continue, or q <return> to quit---
    time=1246937738000000, pwArg=0x0) at ocsp.c:4754
#19 0x005c8089 in CERT_VerifyCert (handle=0xb9bf0170, cert=0xb9c0cd40, 
    checkSig=1, certUsage=certUsageAnyCA, t=1246937738000000, wincx=0x0, 
    log=0x0) at certvfy.c:1503
#20 0x005c1f9f in CERT_VerifyOCSPResponseSignature (response=0xbb4c8ae8, 
    handle=0xb9bf0170, pwArg=0x0, pSignerCert=0xbfb5eb1c, issuer=0xb9c1cf58)
    at ocsp.c:3887
#21 0x005c328b in ocsp_GetOCSPStatusFromNetwork (handle=0xb9bf0170, 
    certID=0xbb4c82d0, cert=0xb9c0cd40, time=1246937737000000, pwArg=0x0, 
    certIDWasConsumed=0xbfb5eb94, rv_ocsp=0xbfb5eb90) at ocsp.c:4875
#22 0x005c307e in CERT_CheckOCSPStatus (handle=0xb9bf0170, cert=0xb9c0cd40, 
    time=1246937737000000, pwArg=0x0) at ocsp.c:4754
#23 0x005c8089 in CERT_VerifyCert (handle=0xb9bf0170, cert=0xb9c0cd40, 
    checkSig=1, certUsage=certUsageAnyCA, t=1246937737000000, wincx=0x0, 
    log=0x0) at certvfy.c:1503
#24 0x005c1f9f in CERT_VerifyOCSPResponseSignature (response=0xbb4c42e0, 
    handle=0xb9bf0170, pwArg=0x0, pSignerCert=0xbfb5eccc, issuer=0xb9c1cf58)
    at ocsp.c:3887
#25 0x005c328b in ocsp_GetOCSPStatusFromNetwork (handle=0xb9bf0170, 
    certID=0xbb4c3ac8, cert=0xb9c0cd40, time=1246937737000000, pwArg=0x0, 
    certIDWasConsumed=0xbfb5ed44, rv_ocsp=0xbfb5ed40) at ocsp.c:4875
#26 0x005c307e in CERT_CheckOCSPStatus (handle=0xb9bf0170, cert=0xb9c0cd40, 
    time=1246937737000000, pwArg=0x0) at ocsp.c:4754
#27 0x005c8089 in CERT_VerifyCert (handle=0xb9bf0170, cert=0xb9c0cd40, 
    checkSig=1, certUsage=certUsageAnyCA, t=1246937737000000, wincx=0x0, 
    log=0x0) at certvfy.c:1503
#28 0x005c1f9f in CERT_VerifyOCSPResponseSignature (response=0xbb4bfad8, 
    handle=0xb9bf0170, pwArg=0x0, pSignerCert=0xbfb5ee7c, issuer=0xb9c1cf58)
    at ocsp.c:3887
#29 0x005c328b in ocsp_GetOCSPStatusFromNetwork (handle=0xb9bf0170, 
    certID=0xbb4bf2c0, cert=0xb9c0cd40, time=1246937737000000, pwArg=0x0, 
    certIDWasConsumed=0xbfb5eef4, rv_ocsp=0xbfb5eef0) at ocsp.c:4875
#30 0x005c307e in CERT_CheckOCSPStatus (handle=0xb9bf0170, cert=0xb9c0cd40, 
    time=1246937737000000, pwArg=0x0) at ocsp.c:4754
#31 0x005c8089 in CERT_VerifyCert (handle=0xb9bf0170, cert=0xb9c0cd40, 
    checkSig=1, certUsage=certUsageAnyCA, t=1246937737000000, wincx=0x0, 
    log=0x0) at certvfy.c:1503
#32 0x005c1f9f in CERT_VerifyOCSPResponseSignature (response=0xbb4bb2d0, 
    handle=0xb9bf0170, pwArg=0x0, pSignerCert=0xbfb5f02c, issuer=0xb9c1cf58)
    at ocsp.c:3887
#33 0x005c328b in ocsp_GetOCSPStatusFromNetwork (handle=0xb9bf0170, 
    certID=0xbb4baab8, cert=0xb9c0cd40, time=1246937737000000, pwArg=0x0, 
    certIDWasConsumed=0xbfb5f0a4, rv_ocsp=0xbfb5f0a0) at ocsp.c:4875
#34 0x005c307e in CERT_CheckOCSPStatus (handle=0xb9bf0170, cert=0xb9c0cd40, 
    time=1246937737000000, pwArg=0x0) at ocsp.c:4754
#35 0x005c8089 in CERT_VerifyCert (handle=0xb9bf0170, cert=0xb9c0cd40, 
    checkSig=1, certUsage=certUsageAnyCA, t=1246937737000000, wincx=0x0, 
    log=0x0) at certvfy.c:1503
#36 0x005c1f9f in CERT_VerifyOCSPResponseSignature (response=0xbb4b6ac8, 
    handle=0xb9bf0170, pwArg=0x0, pSignerCert=0xbfb5f1dc, issuer=0xb9c1cf58)
    at ocsp.c:3887
---Type <return> to continue, or q <return> to quit---
#37 0x005c328b in ocsp_GetOCSPStatusFromNetwork (handle=0xb9bf0170, 
    certID=0xbb4b62b0, cert=0xb9c0cd40, time=1246937737000000, pwArg=0x0, 
    certIDWasConsumed=0xbfb5f254, rv_ocsp=0xbfb5f250) at ocsp.c:4875
#38 0x005c307e in CERT_CheckOCSPStatus (handle=0xb9bf0170, cert=0xb9c0cd40, 
    time=1246937737000000, pwArg=0x0) at ocsp.c:4754
#39 0x005c8089 in CERT_VerifyCert (handle=0xb9bf0170, cert=0xb9c0cd40, 
    checkSig=1, certUsage=certUsageAnyCA, t=1246937737000000, wincx=0x0, 
    log=0x0) at certvfy.c:1503
#40 0x005c1f9f in CERT_VerifyOCSPResponseSignature (response=0xbb4b22c0, 
    handle=0xb9bf0170, pwArg=0x0, pSignerCert=0xbfb5f38c, issuer=0xb9c1cf58)
    at ocsp.c:3887
Comment 72 Jack Magne 2009-07-07 16:22:13 EDT
The other end of the lengthy stack trace:

#2670 0x005c307e in CERT_CheckOCSPStatus (handle=0xb95f01f0, cert=0xb960cdc0, time=1246997917000000, pwArg=0x0)
    at ocsp.c:4754
#2671 0x005c8089 in CERT_VerifyCert (handle=0xb95f01f0, cert=0xb960cdc0, checkSig=1, certUsage=certUsageAnyCA, 
    t=1246997917000000, wincx=0x0, log=0x0) at certvfy.c:1503
#2672 0x005c1f9f in CERT_VerifyOCSPResponseSignature (response=0xb9627848, handle=0xb95f01f0, pwArg=0x0, 
    pSignerCert=0xbfee7c5c, issuer=0xb961cfd8) at ocsp.c:3887
#2673 0x005c328b in ocsp_GetOCSPStatusFromNetwork (handle=0xb95f01f0, certID=0xb9627030, cert=0xb960cdc0, 
    time=1246997917000000, pwArg=0x0, certIDWasConsumed=0xbfee7cd4, rv_ocsp=0xbfee7cd0) at ocsp.c:4875
#2674 0x005c307e in CERT_CheckOCSPStatus (handle=0xb95f01f0, cert=0xb960cdc0, time=1246997917000000, pwArg=0x0)
    at ocsp.c:4754
#2675 0x005c8089 in CERT_VerifyCert (handle=0xb95f01f0, cert=0xb960cdc0, checkSig=1, certUsage=certUsageAnyCA, 
    t=1246997917000000, wincx=0x0, log=0x0) at certvfy.c:1503
#2676 0x005c1f9f in CERT_VerifyOCSPResponseSignature (response=0xb9623040, handle=0xb95f01f0, pwArg=0x0, 
    pSignerCert=0xbfee7e0c, issuer=0xb961cfd8) at ocsp.c:3887
#2677 0x005c328b in ocsp_GetOCSPStatusFromNetwork (handle=0xb95f01f0, certID=0xb9622828, cert=0xb960cdc0, 
---Type <return> to continue, or q <return> to quit---
    time=1246997917000000, pwArg=0x0, certIDWasConsumed=0xbfee7e84, rv_ocsp=0xbfee7e80) at ocsp.c:4875
#2678 0x005c307e in CERT_CheckOCSPStatus (handle=0xb95f01f0, cert=0xb960cdc0, time=1246997917000000, pwArg=0x0)
    at ocsp.c:4754
#2679 0x005c8089 in CERT_VerifyCert (handle=0xb95f01f0, cert=0xb960cdc0, checkSig=1, certUsage=certUsageAnyCA, 
    t=1246997917000000, wincx=0x0, log=0x0) at certvfy.c:1503
#2680 0x005c1f9f in CERT_VerifyOCSPResponseSignature (response=0xb961e838, handle=0xb95f01f0, pwArg=0x0, 
    pSignerCert=0xbfee7fbc, issuer=0xb961cfd8) at ocsp.c:3887
#2681 0x005c328b in ocsp_GetOCSPStatusFromNetwork (handle=0xb95f01f0, certID=0xb961e020, cert=0xb960cdc0, 
    time=1246997917000000, pwArg=0x0, certIDWasConsumed=0xbfee8034, rv_ocsp=0xbfee8030) at ocsp.c:4875
#2682 0x005c307e in CERT_CheckOCSPStatus (handle=0xb95f01f0, cert=0xb960cdc0, time=1246997917000000, pwArg=0x0)
    at ocsp.c:4754
#2683 0x005c8089 in CERT_VerifyCert (handle=0xb95f01f0, cert=0xb960cdc0, checkSig=1, certUsage=certUsageAnyCA, 
    t=1246997917000000, wincx=0x0, log=0x0) at certvfy.c:1503
#2684 0x005c1f9f in CERT_VerifyOCSPResponseSignature (response=0xb961a608, handle=0xb95f01f0, pwArg=0x0, 
    pSignerCert=0xbfee816c, issuer=0xb961cfd8) at ocsp.c:3887
#2685 0x005c328b in ocsp_GetOCSPStatusFromNetwork (handle=0xb95f01f0, certID=0xb95fe690, cert=0xb9619de8, 
    time=1246997917250876, pwArg=0x0, certIDWasConsumed=0xbfee81e4, rv_ocsp=0xbfee81e0) at ocsp.c:4875
#2686 0x005c307e in CERT_CheckOCSPStatus (handle=0xb95f01f0, cert=0xb9619de8, time=1246997917250876, pwArg=0x0)
    at ocsp.c:4754
#2687 0x005c7b4f in CERT_VerifyCertificate (handle=0xb95f01f0, cert=0xb9619de8, checkSig=1, requiredUsages=2, 
    t=1246997917250876, wincx=0x0, log=0x0, returnedUsages=0x0) at certvfy.c:1317
#2688 0x005c814f in CERT_VerifyCertificateNow (handle=0xb95f01f0, cert=0xb9619de8, checkSig=1, requiredUsages=2, 
    wincx=0x0, returnedUsages=0x0) at certvfy.c:1529
#2689 0x00a5fee9 in nss_init_certificate (s=0xb8b94fc8, nickname=0xb8b95fb0 "Server-Cert cert-pki-tps", 
    servercert=0xb8b96c88, serverkey=0xb8b96c8c, KEAtype=0xb8b96c90, model=0xb95ff838, enforce=1)
    at nss_engine_init.c:905
#2690 0x00a603d3 in nss_init_server_certs (s=0xb8b94fc8, p=<value optimized out>, ptemp=<value optimized out>, 
    mctx=0xb8b96c60) at nss_engine_init.c:1018
#2691 0x00a6067d in nss_init_ConfigureServer (s=0xb8b94fc8, p=0xb8b0c5c0, ptemp=0xb8b3c680, sc=0xb8b96be0)
    at nss_engine_init.c:1064
#2692 0x00a60d1a in nss_init_Module (p=0xb8b0c5c0, plog=0xb8b3a678, ptemp=0xb8b3c680, base_server=0xb8b12088)
    at nss_engine_init.c:501
#2693 0xb7f32323 in ap_run_post_config () from /usr/sbin/httpd.worker
#2694 0xb7f1d9ba in main () from /usr/sbin/httpd.worker
Comment 73 Jack Magne 2009-07-07 19:06:10 EDT
The following code in the function CERT_VerifyOCSPResponseSignature  seems to be where the issue can happen:

 /*
     * Just because we have a cert does not mean it is any good; check
     * it for validity, trust and usage.
     */
    if (ocsp_CertIsOCSPDefaultResponder(handle, signerCert)) {
        rv = SECSuccess;
    } else {
        SECCertUsage certUsage;
        if (CERT_IsCACert(signerCert, NULL)) {
            certUsage = certUsageAnyCA;
        } else {
            certUsage = certUsageStatusResponder;
        }
        rv = CERT_VerifyCert(handle, signerCert, PR_TRUE,
                             certUsage, producedAt, pwArg, NULL);
        if (rv != SECSuccess) {
            PORT_SetError(SEC_ERROR_OCSP_INVALID_SIGNING_CERT);
            goto finish;
        }
    }

    rv = ocsp_VerifyResponseSignature(signerCert, signature,
                                      tbsResponseDataDER,
                                      pwArg);

finish:


If we have configured everything to make this the default responder, this all goes away. If not , it tries to verify the OCSP signing cert, which takes us into the infinite loop. I have no idea how to resolve this. Perhaps a flag somewhere that indicates that a given cert is already in the middle of verification would help.

Note You need to log in before you can comment on or make changes to this bug.